lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4711 - Still Failing
Date Mon, 26 May 2014 04:41:33 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4711/

2 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.MultiThreadedOCPTest

Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.MultiThreadedOCPTest:     1) Thread[id=14260, name=parallelCoreAdminExecutor-3579-thread-1, state=WAITING, group=TGRP-MultiThreadedOCPTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)         at java.lang.Thread.run(Thread.java:724)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.MultiThreadedOCPTest: 
   1) Thread[id=14260, name=parallelCoreAdminExecutor-3579-thread-1, state=WAITING, group=TGRP-MultiThreadedOCPTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:724)
	at __randomizedtesting.SeedInfo.seed([283CF5F9411C467D]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.MultiThreadedOCPTest

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=14260, name=parallelCoreAdminExecutor-3579-thread-1, state=WAITING, group=TGRP-MultiThreadedOCPTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)         at java.lang.Thread.run(Thread.java:724)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=14260, name=parallelCoreAdminExecutor-3579-thread-1, state=WAITING, group=TGRP-MultiThreadedOCPTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:724)
	at __randomizedtesting.SeedInfo.seed([283CF5F9411C467D]:0)




Build Log:
[...truncated 11562 lines...]
   [junit4] Suite: org.apache.solr.cloud.MultiThreadedOCPTest
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/init-core-data-001
   [junit4]   2> 3652726 T14135 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 3652726 T14135 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_o/
   [junit4]   2> 3652732 T14135 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 3652733 T14135 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3652734 T14136 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 3652835 T14135 oasc.ZkTestServer.run start zk server on port:18249
   [junit4]   2> 3652835 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3652841 T14142 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c3a3f22 name:ZooKeeperConnection Watcher:127.0.0.1:18249 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3652842 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3652842 T14135 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 3652862 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3652864 T14144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2319ad49 name:ZooKeeperConnection Watcher:127.0.0.1:18249/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3652864 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3652865 T14135 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 3652873 T14135 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 3652876 T14135 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 3652878 T14135 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 3652887 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 3652887 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 3652900 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 3652901 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 3653007 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3653008 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3653010 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 3653011 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 3653020 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 3653020 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 3653023 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 3653024 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 3653026 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 3653027 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 3653030 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3653031 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3653033 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3653034 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3653037 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 3653037 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 3653040 T14135 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 3653041 T14135 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 3654163 T14135 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3654166 T14135 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:60525
   [junit4]   2> 3654166 T14135 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3654167 T14135 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3654167 T14135 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002
   [junit4]   2> 3654167 T14135 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002/'
   [junit4]   2> 3654196 T14135 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002/solr.xml
   [junit4]   2> 3654269 T14135 oasc.CoreContainer.<init> New CoreContainer 1423414244
   [junit4]   2> 3654270 T14135 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002/]
   [junit4]   2> 3654271 T14135 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3654271 T14135 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3654272 T14135 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3654272 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3654272 T14135 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3654273 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3654273 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3654273 T14135 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3654274 T14135 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3654274 T14135 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3654275 T14135 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3654275 T14135 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3654275 T14135 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:18249/solr
   [junit4]   2> 3654276 T14135 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3654276 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3654279 T14155 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@152e8940 name:ZooKeeperConnection Watcher:127.0.0.1:18249 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3654279 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3654295 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3654297 T14157 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@769f2015 name:ZooKeeperConnection Watcher:127.0.0.1:18249/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3654297 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3654299 T14135 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 3654309 T14135 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 3654313 T14135 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 3654316 T14135 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 3654319 T14135 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 3654322 T14135 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 3654324 T14135 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60525__o
   [junit4]   2> 3654325 T14135 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60525__o
   [junit4]   2> 3654327 T14135 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 3654329 T14135 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 3654342 T14135 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60525__o
   [junit4]   2> 3654342 T14135 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3654344 T14135 oasc.Overseer.start Overseer (id=91821118201724931-127.0.0.1:60525__o-n_0000000000) starting
   [junit4]   2> 3654353 T14135 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 3654370 T14159 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3654371 T14135 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 3654373 T14135 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 3654375 T14135 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3654377 T14158 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3654382 T14160 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 3654382 T14160 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3654383 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3654383 T14160 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3654384 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3654385 T14158 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:60525/_o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:60525__o",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3654386 T14158 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 3654386 T14158 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3654389 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3654399 T14157 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> 3655385 T14160 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3655385 T14160 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 3655386 T14160 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3655386 T14160 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 3655387 T14160 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3655388 T14160 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002/collection1/'
   [junit4]   2> 3655390 T14160 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 3655391 T14160 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 3655392 T14160 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 3655472 T14160 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 3655582 T14160 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3655686 T14160 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3655712 T14160 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3656345 T14160 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 3656361 T14160 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3656365 T14160 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3656378 T14160 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3656381 T14160 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3656385 T14160 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 3656386 T14160 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 3656386 T14160 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 3656386 T14160 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 3656387 T14160 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 3656387 T14160 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 3656387 T14160 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 3656388 T14160 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3656388 T14160 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-002/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-001/control/data/
   [junit4]   2> 3656388 T14160 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b201e2d
   [junit4]   2> 3656389 T14160 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-001/control/data
   [junit4]   2> 3656389 T14160 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-001/control/data/index/
   [junit4]   2> 3656390 T14160 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 3656390 T14160 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-001/control/data/index
   [junit4]   2> 3656390 T14160 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 3656391 T14160 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@701ee221 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@246ae721),segFN=segments_1,generation=1}
   [junit4]   2> 3656391 T14160 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3656394 T14160 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3656394 T14160 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3656395 T14160 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3656395 T14160 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3656395 T14160 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3656396 T14160 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3656396 T14160 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3656396 T14160 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3656397 T14160 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3656397 T14160 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3656397 T14160 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3656398 T14160 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3656398 T14160 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3656398 T14160 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3656399 T14160 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3656399 T14160 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3656399 T14160 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 3656411 T14160 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3656417 T14160 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3656417 T14160 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3656418 T14160 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1915417957, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 3656418 T14160 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@701ee221 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@246ae721),segFN=segments_1,generation=1}
   [junit4]   2> 3656419 T14160 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3656419 T14160 oass.SolrIndexSearcher.<init> Opening Searcher@13f0ea97[collection1] main
   [junit4]   2> 3656419 T14160 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 3656420 T14160 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3656421 T14160 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3656421 T14160 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3656421 T14160 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3656421 T14160 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3656422 T14160 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3656422 T14160 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3656422 T14160 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3656423 T14160 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3656425 T14161 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@13f0ea97[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 3656426 T14160 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3656427 T14164 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60525/_o collection:control_collection shard:shard1
   [junit4]   2> 3656427 T14135 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 3656428 T14164 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 3656428 T14135 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3656429 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3656431 T14166 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27abeac7 name:ZooKeeperConnection Watcher:127.0.0.1:18249/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3656431 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3656447 T14135 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3656450 T14164 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 3656450 T14135 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 3656452 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3656453 T14164 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3656453 T14164 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1855 name=collection1 org.apache.solr.core.SolrCore@3bef4071 url=http://127.0.0.1:60525/_o/collection1 node=127.0.0.1:60525__o C1855_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:60525/_o, core=collection1, node_name=127.0.0.1:60525__o}
   [junit4]   2> 3656453 T14164 C1855 P60525 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60525/_o/collection1/
   [junit4]   2> 3656453 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3656454 T14164 C1855 P60525 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3656454 T14164 C1855 P60525 oasc.SyncStrategy.syncToMe http://127.0.0.1:60525/_o/collection1/ has no replicas
   [junit4]   2> 3656454 T14164 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60525/_o/collection1/ shard1
   [junit4]   2> 3656455 T14164 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 3656457 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3656467 T14157 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> 3656467 T14166 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> 3656484 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3656485 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3656488 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3656591 T14166 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> 3656591 T14157 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> 3656638 T14164 oasc.ZkController.register We are http://127.0.0.1:60525/_o/collection1/ and leader is http://127.0.0.1:60525/_o/collection1/
   [junit4]   2> 3656638 T14164 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60525/_o
   [junit4]   2> 3656638 T14164 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3656638 T14164 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 3656638 T14164 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3656640 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3656640 T14164 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3656640 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3656641 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3656641 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3656641 T14158 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:60525/_o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:60525__o",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 3656644 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3656746 T14157 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> 3656746 T14166 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> 3657603 T14135 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 3657604 T14135 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3657607 T14135 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:47443
   [junit4]   2> 3657608 T14135 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3657608 T14135 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3657608 T14135 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003
   [junit4]   2> 3657609 T14135 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/'
   [junit4]   2> 3657637 T14135 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/solr.xml
   [junit4]   2> 3657711 T14135 oasc.CoreContainer.<init> New CoreContainer 934728811
   [junit4]   2> 3657711 T14135 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/]
   [junit4]   2> 3657713 T14135 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3657713 T14135 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3657713 T14135 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3657714 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3657714 T14135 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3657714 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3657715 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3657715 T14135 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3657715 T14135 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3657716 T14135 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3657716 T14135 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3657716 T14135 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3657717 T14135 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:18249/solr
   [junit4]   2> 3657717 T14135 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3657718 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3657721 T14177 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4433d960 name:ZooKeeperConnection Watcher:127.0.0.1:18249 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3657721 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3657738 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3657740 T14179 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7041f46e name:ZooKeeperConnection Watcher:127.0.0.1:18249/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3657740 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3657754 T14135 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3658757 T14135 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47443__o
   [junit4]   2> 3658759 T14135 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47443__o
   [junit4]   2> 3658783 T14180 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 3658783 T14180 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3658785 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3658785 T14180 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3658785 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3658785 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3658786 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3658786 T14158 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:47443/_o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:47443__o",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3658787 T14158 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 3658787 T14158 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 3658790 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3658800 T14157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3658800 T14179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3658800 T14166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3659786 T14180 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3659786 T14180 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 3659787 T14180 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3659787 T14180 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3659788 T14180 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3659788 T14180 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/'
   [junit4]   2> 3659791 T14180 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 3659792 T14180 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 3659793 T14180 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 3659889 T14180 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 3659982 T14180 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3660084 T14180 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3660101 T14180 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3660784 T14180 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 3660796 T14180 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3660799 T14180 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3660809 T14180 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3660813 T14180 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3660816 T14180 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 3660817 T14180 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 3660817 T14180 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 3660818 T14180 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 3660818 T14180 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 3660819 T14180 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 3660819 T14180 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 3660819 T14180 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3660819 T14180 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/data/
   [junit4]   2> 3660820 T14180 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b201e2d
   [junit4]   2> 3660821 T14180 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/data
   [junit4]   2> 3660821 T14180 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/data/index/
   [junit4]   2> 3660821 T14180 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 3660821 T14180 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-003/collection1/data/index
   [junit4]   2> 3660822 T14180 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 3660822 T14180 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1de8113e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f373ca7),segFN=segments_1,generation=1}
   [junit4]   2> 3660823 T14180 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3660826 T14180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3660827 T14180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3660827 T14180 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3660827 T14180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3660828 T14180 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3660828 T14180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3660828 T14180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3660828 T14180 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3660829 T14180 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3660829 T14180 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3660830 T14180 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3660830 T14180 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3660830 T14180 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3660831 T14180 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3660831 T14180 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3660832 T14180 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3660832 T14180 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 3660846 T14180 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3660852 T14180 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3660852 T14180 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3660853 T14180 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1915417957, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 3660854 T14180 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1de8113e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f373ca7),segFN=segments_1,generation=1}
   [junit4]   2> 3660854 T14180 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3660854 T14180 oass.SolrIndexSearcher.<init> Opening Searcher@227c9a94[collection1] main
   [junit4]   2> 3660855 T14180 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3660856 T14180 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3660856 T14180 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3660856 T14180 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3660857 T14180 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3660857 T14180 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3660857 T14180 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3660858 T14180 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3660858 T14180 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3660858 T14180 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3660862 T14181 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@227c9a94[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 3660864 T14180 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3660865 T14184 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47443/_o collection:collection1 shard:shard2
   [junit4]   2> 3660865 T14135 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 3660866 T14184 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 3660866 T14135 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3660916 T14184 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 3660919 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3660919 T14184 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3660920 T14184 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1856 name=collection1 org.apache.solr.core.SolrCore@5158a2d7 url=http://127.0.0.1:47443/_o/collection1 node=127.0.0.1:47443__o C1856_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:47443/_o, core=collection1, node_name=127.0.0.1:47443__o}
   [junit4]   2> 3660920 T14184 C1856 P47443 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47443/_o/collection1/
   [junit4]   2> 3660921 T14184 C1856 P47443 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3660921 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3660921 T14184 C1856 P47443 oasc.SyncStrategy.syncToMe http://127.0.0.1:47443/_o/collection1/ has no replicas
   [junit4]   2> 3660922 T14184 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47443/_o/collection1/ shard2
   [junit4]   2> 3660922 T14184 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 3660969 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3661014 T14179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3661014 T14166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3661014 T14157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3661065 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3661066 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3661069 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3661171 T14157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3661171 T14166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3661171 T14179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3661218 T14184 oasc.ZkController.register We are http://127.0.0.1:47443/_o/collection1/ and leader is http://127.0.0.1:47443/_o/collection1/
   [junit4]   2> 3661218 T14184 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47443/_o
   [junit4]   2> 3661218 T14184 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3661218 T14184 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 3661219 T14184 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3661220 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3661220 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3661221 T14184 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3661221 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3661222 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3661222 T14158 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:47443/_o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:47443__o",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 3661234 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3661341 T14179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3661341 T14157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3661341 T14166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 3662262 T14135 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 3662262 T14135 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3662265 T14135 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:64784
   [junit4]   2> 3662266 T14135 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3662266 T14135 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3662266 T14135 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004
   [junit4]   2> 3662267 T14135 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/'
   [junit4]   2> 3662308 T14135 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/solr.xml
   [junit4]   2> 3662406 T14135 oasc.CoreContainer.<init> New CoreContainer 1829802943
   [junit4]   2> 3662406 T14135 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/]
   [junit4]   2> 3662408 T14135 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3662408 T14135 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3662409 T14135 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3662409 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3662409 T14135 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3662410 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3662410 T14135 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3662410 T14135 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3662410 T14135 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3662411 T14135 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3662411 T14135 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3662412 T14135 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3662412 T14135 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:18249/solr
   [junit4]   2> 3662412 T14135 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3662413 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3662442 T14195 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b541889 name:ZooKeeperConnection Watcher:127.0.0.1:18249 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3662442 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3662445 T14135 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3662454 T14197 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4cebad6 name:ZooKeeperConnection Watcher:127.0.0.1:18249/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3662454 T14135 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3662469 T14135 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3663471 T14135 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64784__o
   [junit4]   2> 3663473 T14135 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64784__o
   [junit4]   2> 3663492 T14198 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 3663493 T14198 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3663494 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3663494 T14198 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3663494 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3663495 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3663495 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3663496 T14158 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:64784/_o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64784__o",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3663496 T14158 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 3663496 T14158 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3663505 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3663506 T14197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3663506 T14179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3663506 T14157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3663506 T14166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3664495 T14198 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3664495 T14198 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 3664496 T14198 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3664496 T14198 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3664497 T14198 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3664497 T14198 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/'
   [junit4]   2> 3664499 T14198 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 3664500 T14198 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 3664501 T14198 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 3664591 T14198 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 3664682 T14198 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3664785 T14198 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3664802 T14198 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3665501 T14198 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 3665520 T14198 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3665525 T14198 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3665537 T14198 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3665543 T14198 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3665549 T14198 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 3665550 T14198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 3665550 T14198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 3665550 T14198 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 3665551 T14198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 3665552 T14198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 3665552 T14198 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 3665552 T14198 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3665553 T14198 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/data/
   [junit4]   2> 3665553 T14198 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b201e2d
   [junit4]   2> 3665555 T14198 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/data
   [junit4]   2> 3665555 T14198 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/data/index/
   [junit4]   2> 3665556 T14198 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 3665556 T14198 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-004/collection1/data/index
   [junit4]   2> 3665557 T14198 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 3665558 T14198 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3b1dc671 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5034b04),segFN=segments_1,generation=1}
   [junit4]   2> 3665558 T14198 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3665563 T14198 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3665564 T14198 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3665564 T14198 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3665564 T14198 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3665565 T14198 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3665565 T14198 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3665566 T14198 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3665566 T14198 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3665566 T14198 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3665567 T14198 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3665568 T14198 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3665568 T14198 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3665569 T14198 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3665569 T14198 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3665570 T14198 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3665571 T14198 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3665571 T14198 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 3665598 T14198 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3665605 T14198 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3665606 T14198 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3665607 T14198 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1915417957, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 3665608 T14198 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3b1dc671 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5034b04),segFN=segments_1,generation=1}
   [junit4]   2> 3665608 T14198 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3665608 T14198 oass.SolrIndexSearcher.<init> Opening Searcher@53509f3d[collection1] main
   [junit4]   2> 3665609 T14198 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3665610 T14198 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3665610 T14198 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3665611 T14198 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3665611 T14198 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3665611 T14198 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3665612 T14198 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3665612 T14198 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3665612 T14198 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3665613 T14198 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3665617 T14199 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53509f3d[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 3665620 T14198 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3665621 T14202 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:64784/_o collection:collection1 shard:shard1
   [junit4]   2> 3665621 T14135 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 3665622 T14135 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3665622 T14202 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3665637 T14202 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 3665645 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3665645 T14202 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3665645 T14202 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1857 name=collection1 org.apache.solr.core.SolrCore@2d4eb7db url=http://127.0.0.1:64784/_o/collection1 node=127.0.0.1:64784__o C1857_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:64784/_o, core=collection1, node_name=127.0.0.1:64784__o}
   [junit4]   2> 3665645 T14202 C1857 P64784 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:64784/_o/collection1/
   [junit4]   2> 3665646 T14202 C1857 P64784 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3665646 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3665646 T14202 C1857 P64784 oasc.SyncStrategy.syncToMe http://127.0.0.1:64784/_o/collection1/ has no replicas
   [junit4]   2> 3665647 T14202 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:64784/_o/collection1/ shard1
   [junit4]   2> 3665647 T14202 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3665663 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3665805 T14157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3665805 T14197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3665805 T14166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3665806 T14179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3665836 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3665844 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3665946 T14166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3665946 T14157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3665946 T14179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3665946 T14197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3666040 T14202 oasc.ZkController.register We are http://127.0.0.1:64784/_o/collection1/ and leader is http://127.0.0.1:64784/_o/collection1/
   [junit4]   2> 3666040 T14202 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64784/_o
   [junit4]   2> 3666040 T14202 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3666040 T14202 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 3666041 T14202 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3666042 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3666043 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3666043 T14202 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3666043 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3666044 T14158 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3666045 T14158 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:64784/_o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64784__o",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 3666081 T14157 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3666186 T14157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3666186 T14166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3666186 T14179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3666186 T14197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 3666827 T14135 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 3666828 T14135 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3666831 T14135 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13609
   [junit4]   2> 3666832 T14135 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3666832 T14135 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3666832 T14135 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-005
   [junit4]   2> 3666833 T14135 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-005/'
   [junit4]   2> 3666861 T14135 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-283CF5F9411C467D-001/tempDir-005/solr.xml
   [junit4]   2> 3666934 T14135 oasc.CoreContainer.<init> New CoreContainer 1178528281
   [junit4]   2> 3666935 T14135 oasc.CoreContainer.load Loa

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

it4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
   [junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 86158 T14134 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
   [junit4]   2> 	   1) Thread[id=14260, name=parallelCoreAdminExecutor-3579-thread-1, state=WAITING, group=TGRP-MultiThreadedOCPTest]
   [junit4]   2> 89165 T14134 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
   [junit4]   2> 	   1) Thread[id=14260, name=parallelCoreAdminExecutor-3579-thread-1, state=WAITING, group=TGRP-MultiThreadedOCPTest]
   [junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
   [junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
   [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
   [junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=ro, timezone=PLT
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=92652208,total=523239424
   [junit4]   2> NOTE: All tests run in this JVM: [DefaultValueUpdateProcessorTest, HttpPartitionTest, AlternateDirectoryTest, DeleteInactiveReplicaTest, TestCSVLoader, DocValuesMissingTest, TestLRUCache, HdfsWriteToMultipleCollectionsTest, SpellCheckCollatorTest, TestShardHandlerFactory, TestUpdate, TestBinaryField, TestReload, TestNoOpRegenerator, ShardRoutingCustomTest, DOMUtilTest, TestFiltering, TestDistributedSearch, MultiTermTest, ZkSolrClientTest, TestWordDelimiterFilterFactory, ShardSplitTest, SolrIndexConfigTest, TestSolrJ, TestManagedSynonymFilterFactory, TestSolrXMLSerializer, TestCodecSupport, OverseerStatusTest, TestSolr4Spatial, QueryResultKeyTest, DeleteReplicaTest, CollectionsAPIDistributedZkTest, DateFieldTest, TestStressLucene, DocumentAnalysisRequestHandlerTest, ChangedSchemaMergeTest, TestMultiCoreConfBootstrap, TestSolrCoreProperties, ResourceLoaderTest, BasicZkTest, TestManagedResource, SolrCoreCheckLockOnStartupTest, SuggesterWFSTTest, TestIBSimilarityFactory, CachingDirectoryFactoryTest, NoCacheHeaderTest, TestFieldTypeResource, TestDistributedGrouping, TestArbitraryIndexDir, TestFastOutputStream, MinimalSchemaTest, TestConfigSets, TestSolrXml, ZkNodePropsTest, HardAutoCommitTest, TestFoldingMultitermQuery, FieldAnalysisRequestHandlerTest, SolrCmdDistributorTest, TestRandomFaceting, FieldFacetExtrasTest, TestAnalyzedSuggestions, DateMathParserTest, PingRequestHandlerTest, HighlighterConfigTest, TestDynamicFieldResource, DisMaxRequestHandlerTest, AtomicUpdatesTest, TestRecoveryHdfs, TestSweetSpotSimilarityFactory, CustomCollectionTest, JSONWriterTest, NotRequiredUniqueKeyTest, BasicDistributedZk2Test, CoreContainerCoreInitFailuresTest, TestQuerySenderNoQuery, TestLMDirichletSimilarityFactory, NoFacetTest, HdfsUnloadDistributedZkTest, TestJmxIntegration, TestQuerySenderListener, TestIndexingPerformance, TestRecovery, TestCoreDiscovery, FileUtilsTest, TestStressRecovery, CoreMergeIndexesAdminHandlerTest, DirectUpdateHandlerTest, TestManagedSchema, TestStressUserVersions, IndexBasedSpellCheckerTest, ResponseHeaderTest, TestOmitPositions, StatsComponentTest, SuggestComponentTest, LegacyHTMLStripCharFilterTest, TestQueryTypes, TestFuzzyAnalyzedSuggestions, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, SyncSliceTest, TestFaceting, TestHashPartitioner, TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, DistributedTermsComponentTest, SimpleFacetsTest, SolrCoreTest, BadIndexSchemaTest, ConvertedLegacyTest, TestFunctionQuery, BasicFunctionalityTest, TestIndexSearcher, HighlighterTest, SoftAutoCommitTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, SuggesterFSTTest, SolrRequestParserTest, SuggesterTSTTest, PolyFieldTest, FieldMutatingUpdateProcessorTest, QueryEqualityTest, StatelessScriptUpdateProcessorFactoryTest, DistanceFunctionTest, DebugComponentTest, TestQueryUtils, TestWriterPerf, FileBasedSpellCheckerTest, RequestHandlersTest, TermVectorComponentTest, RequiredFieldsTest, LoggingHandlerTest, TestCollationField, ReturnFieldsTest, UniqFieldsUpdateProcessorFactoryTest, TestPartialUpdateDeduplication, TestComponentsName, TestBinaryResponseWriter, UpdateParamsTest, TestMergePolicyConfig, TestDocSet, NumericFieldsTest, OutputWriterTest, DirectSolrConnectionTest, TestPhraseSuggestions, TestXIncludeConfig, TestLMJelinekMercerSimilarityFactory, TimeZoneUtilsTest, OpenExchangeRatesOrgProviderTest, PluginInfoTest, PreAnalyzedFieldTest, RAMDirectoryFactoryTest, TestUtils, CircularListTest, CursorPagingTest, AbstractAnalyticsFacetTest, FieldFacetTest, RangeFacetTest, AliasIntegrationTest, ConnectionManagerTest, DistribCursorPagingTest, MultiThreadedOCPTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=MultiThreadedOCPTest -Dtests.seed=283CF5F9411C467D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ro -Dtests.timezone=PLT -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s J1 | MultiThreadedOCPTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.MultiThreadedOCPTest: 
   [junit4]    >    1) Thread[id=14260, name=parallelCoreAdminExecutor-3579-thread-1, state=WAITING, group=TGRP-MultiThreadedOCPTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
   [junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:724)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([283CF5F9411C467D]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=14260, name=parallelCoreAdminExecutor-3579-thread-1, state=WAITING, group=TGRP-MultiThreadedOCPTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
   [junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:724)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([283CF5F9411C467D]:0)
   [junit4] Completed on J1 in 89.24s, 1 test, 2 errors <<< FAILURES!

[...truncated 213 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:467: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1296: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:920: There were test failures: 406 suites, 1688 tests, 2 suite-level errors, 221 ignored (15 assumptions)

Total time: 104 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message