lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_60-ea-b01) - Build # 3619 - Still Failing!
Date Mon, 30 Dec 2013 01:02:25 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3619/
Java: 64bit/jdk1.7.0_60-ea-b01 -XX:+UseCompressedOops -XX:+UseSerialGC

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

Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:     1) Thread[id=9379, name=Timer-644, state=WAITING, group=TGRP-ShardSplitTest]         at java.lang.Object.wait(Native Method)         at java.lang.Object.wait(Object.java:503)         at java.util.TimerThread.mainLoop(Timer.java:526)         at java.util.TimerThread.run(Timer.java:505)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest: 
   1) Thread[id=9379, name=Timer-644, state=WAITING, group=TGRP-ShardSplitTest]
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:503)
        at java.util.TimerThread.mainLoop(Timer.java:526)
        at java.util.TimerThread.run(Timer.java:505)
	at __randomizedtesting.SeedInfo.seed([F1296F39E51835C6]:0)


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

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=9379, name=Timer-644, state=WAITING, group=TGRP-ShardSplitTest]         at java.lang.Object.wait(Native Method)         at java.lang.Object.wait(Object.java:503)         at java.util.TimerThread.mainLoop(Timer.java:526)         at java.util.TimerThread.run(Timer.java:505)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=9379, name=Timer-644, state=WAITING, group=TGRP-ShardSplitTest]
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:503)
        at java.util.TimerThread.mainLoop(Timer.java:526)
        at java.util.TimerThread.run(Timer.java:505)
	at __randomizedtesting.SeedInfo.seed([F1296F39E51835C6]:0)




Build Log:
[...truncated 10819 lines...]
   [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
   [junit4]   2> 2459631 T9097 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /cza/f
   [junit4]   2> 2459642 T9097 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-ShardSplitTest-1388365161797
   [junit4]   2> 2459645 T9097 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2459648 T9098 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2459746 T9097 oasc.ZkTestServer.run start zk server on port:53946
   [junit4]   2> 2459749 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2459766 T9105 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33c15f60 name:ZooKeeperConnection Watcher:127.0.0.1:53946 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2459767 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2459767 T9097 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2459785 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2459789 T9108 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f958567 name:ZooKeeperConnection Watcher:127.0.0.1:53946/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2459793 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2459793 T9097 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 2459798 T9097 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 2459801 T9097 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 2459804 T9097 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 2459807 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 2459807 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 2459815 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 2459815 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 2459820 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2459820 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2459827 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 2459827 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 2459834 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 2459834 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 2459840 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 2459840 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 2459846 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 2459846 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 2459854 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2459854 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2459862 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2459862 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2459870 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 2459870 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 2459880 T9097 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 2459880 T9097 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 2460516 T9097 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2460526 T9097 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53953
   [junit4]   2> 2460526 T9097 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2460526 T9097 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2460526 T9097 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043
   [junit4]   2> 2460529 T9097 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043\'
   [junit4]   2> 2460583 T9097 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043\solr.xml
   [junit4]   2> 2460642 T9097 oasc.CoreContainer.<init> New CoreContainer 246198640
   [junit4]   2> 2460642 T9097 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043\]
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2460645 T9097 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2460654 T9097 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2460654 T9097 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2460657 T9097 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2460657 T9097 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53946/solr
   [junit4]   2> 2460657 T9097 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2460660 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2460685 T9120 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71da8f7d name:ZooKeeperConnection Watcher:127.0.0.1:53946 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2460686 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2460692 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2460699 T9123 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a7a31db name:ZooKeeperConnection Watcher:127.0.0.1:53946/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2460700 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2460703 T9097 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2460710 T9097 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2460717 T9097 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2460722 T9097 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53953_cza%2Ff
   [junit4]   2> 2460726 T9097 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53953_cza%2Ff
   [junit4]   2> 2460733 T9097 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2460746 T9097 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2460751 T9097 oasc.Overseer.start Overseer (id=90987899244118019-127.0.0.1:53953_cza%2Ff-n_0000000000) starting
   [junit4]   2> 2460760 T9097 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2460776 T9097 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2460779 T9125 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2460785 T9097 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2460791 T9097 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2460800 T9124 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2460810 T9126 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 2460810 T9126 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2460813 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2460814 T9126 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2460817 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2460818 T9124 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:53953/cza/f",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53953_cza%2Ff",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2460818 T9124 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 2460818 T9124 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2460824 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2460825 T9123 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> 2461796 T9126 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2461796 T9126 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043\collection1
   [junit4]   2> 2461796 T9126 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 2461797 T9126 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2461797 T9126 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 2461800 T9126 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043\collection1\'
   [junit4]   2> 2461804 T9126 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043/collection1/lib/classes/' to classloader
   [junit4]   2> 2461804 T9126 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043/collection1/lib/README' to classloader
   [junit4]   2> 2461891 T9126 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 2461979 T9126 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2461982 T9126 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2461992 T9126 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2462498 T9126 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2462502 T9126 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2462505 T9126 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2462515 T9126 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2462555 T9126 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2462556 T9126 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1388365162043\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1388365161795/control/data\
   [junit4]   2> 2462556 T9126 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2368e4dd
   [junit4]   2> 2462557 T9126 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1388365161795/control/data\
   [junit4]   2> 2462557 T9126 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1388365161795/control/data\index/
   [junit4]   2> 2462557 T9126 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1388365161795\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 2462559 T9126 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1388365161795/control/data\index
   [junit4]   2> 2462560 T9126 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=65.3857421875, floorSegmentMB=1.9580078125, forceMergeDeletesPctAllowed=16.3276992108044, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2462560 T9126 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5c620d2f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@25fdbaa),segFN=segments_1,generation=1}
   [junit4]   2> 2462560 T9126 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2462566 T9126 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2462567 T9126 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2462567 T9126 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2462568 T9126 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2462568 T9126 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2462568 T9126 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2462570 T9126 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2462571 T9126 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2462571 T9126 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2462572 T9126 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2462573 T9126 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2462573 T9126 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2462573 T9126 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2462575 T9126 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2462575 T9126 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2462576 T9126 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2462576 T9126 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2462591 T9126 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2462601 T9126 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2462601 T9126 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2462603 T9126 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=59.8974609375, floorSegmentMB=0.859375, forceMergeDeletesPctAllowed=21.36537977082747, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2462603 T9126 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5c620d2f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@25fdbaa),segFN=segments_1,generation=1}
   [junit4]   2> 2462603 T9126 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2462603 T9126 oass.SolrIndexSearcher.<init> Opening Searcher@458c2f36 main
   [junit4]   2> 2462611 T9126 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2462612 T9127 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@458c2f36 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2462615 T9097 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2462616 T9097 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2462628 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2462631 T9130 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53953/cza/f collection:control_collection shard:shard1
   [junit4]   2> 2462639 T9130 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 2462643 T9133 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5bb8884e name:ZooKeeperConnection Watcher:127.0.0.1:53946/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2462644 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2462650 T9097 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2462663 T9097 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 2463312 T9097 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2463320 T9097 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53965
   [junit4]   2> 2463320 T9097 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2463320 T9097 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2463320 T9097 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816
   [junit4]   2> 2463320 T9097 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816\'
   [junit4]   2> 2463361 T9097 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816\solr.xml
   [junit4]   2> 2463449 T9097 oasc.CoreContainer.<init> New CoreContainer 1145551315
   [junit4]   2> 2463449 T9097 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816\]
   [junit4]   2> 2463453 T9097 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2463453 T9097 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2463453 T9097 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2463453 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2463453 T9097 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2463453 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2463453 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2463453 T9097 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2463455 T9097 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2463470 T9097 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2463473 T9097 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2463473 T9097 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2463475 T9097 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53946/solr
   [junit4]   2> 2463475 T9097 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2463480 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2463513 T9130 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2463537 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2463539 T9147 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a2c338f name:ZooKeeperConnection Watcher:127.0.0.1:53946 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2463539 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2463545 T9130 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2463545 T9130 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4852 name=collection1 org.apache.solr.core.SolrCore@a2dd69 url=http://127.0.0.1:53953/cza/f/collection1 node=127.0.0.1:53953_cza%2Ff C4852_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:53953/cza/f, core=collection1, node_name=127.0.0.1:53953_cza%2Ff}
   [junit4]   2> 2463545 T9130 C4852 P53953 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53953/cza/f/collection1/
   [junit4]   2> 2463545 T9130 C4852 P53953 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2463545 T9130 C4852 P53953 oasc.SyncStrategy.syncToMe http://127.0.0.1:53953/cza/f/collection1/ has no replicas
   [junit4]   2> 2463545 T9130 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53953/cza/f/collection1/ shard1
   [junit4]   2> 2463546 T9130 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 2463557 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2463566 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2463568 T9150 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6016614a name:ZooKeeperConnection Watcher:127.0.0.1:53946/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2463570 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2463588 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2463591 T9133 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> 2463592 T9123 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> 2463600 T9097 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2463613 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2463620 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2463724 T9133 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> 2463726 T9123 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> 2463726 T9150 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> 2463752 T9130 oasc.ZkController.register We are http://127.0.0.1:53953/cza/f/collection1/ and leader is http://127.0.0.1:53953/cza/f/collection1/
   [junit4]   2> 2463752 T9130 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53953/cza/f
   [junit4]   2> 2463752 T9130 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2463752 T9130 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 2463752 T9130 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2463756 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2463756 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2463756 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2463758 T9130 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2463760 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2463760 T9124 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:53953/cza/f",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53953_cza%2Ff",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 2463766 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2463880 T9123 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> 2463881 T9150 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> 2463881 T9133 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> 2464678 T9097 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53965_cza%2Ff
   [junit4]   2> 2464684 T9097 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53965_cza%2Ff
   [junit4]   2> 2464693 T9150 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2464694 T9123 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2464695 T9133 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2464710 T9151 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 2464711 T9151 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2464714 T9151 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2464714 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2464714 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2464714 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2464718 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2464719 T9124 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:53965/cza/f",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53965_cza%2Ff",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2464719 T9124 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 2464719 T9124 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2464728 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2464846 T9133 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> 2464847 T9123 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> 2464847 T9150 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> 2465792 T9151 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2465792 T9151 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816\collection1
   [junit4]   2> 2465792 T9151 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2465794 T9151 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2465795 T9151 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2465797 T9151 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816\collection1\'
   [junit4]   2> 2465802 T9151 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816/collection1/lib/classes/' to classloader
   [junit4]   2> 2465807 T9151 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816/collection1/lib/README' to classloader
   [junit4]   2> 2465909 T9151 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 2465985 T9151 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2465989 T9151 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2466006 T9151 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2466667 T9151 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2466670 T9151 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2466672 T9151 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2466679 T9151 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2466729 T9151 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2466730 T9151 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1388365164816\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty1\
   [junit4]   2> 2466730 T9151 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2368e4dd
   [junit4]   2> 2466731 T9151 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty1\
   [junit4]   2> 2466731 T9151 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty1\index/
   [junit4]   2> 2466731 T9151 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1388365161795\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 2466732 T9151 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty1\index
   [junit4]   2> 2466733 T9151 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=65.3857421875, floorSegmentMB=1.9580078125, forceMergeDeletesPctAllowed=16.3276992108044, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2466734 T9151 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2d3cc7fe lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7a4ae49),segFN=segments_1,generation=1}
   [junit4]   2> 2466734 T9151 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2466739 T9151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2466741 T9151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2466741 T9151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2466741 T9151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2466742 T9151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2466742 T9151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2466743 T9151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2466743 T9151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2466743 T9151 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2466744 T9151 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2466745 T9151 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2466745 T9151 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2466745 T9151 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2466746 T9151 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2466746 T9151 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2466747 T9151 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2466747 T9151 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2466758 T9151 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2466782 T9151 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2466782 T9151 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2466783 T9151 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=59.8974609375, floorSegmentMB=0.859375, forceMergeDeletesPctAllowed=21.36537977082747, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2466783 T9151 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2d3cc7fe lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7a4ae49),segFN=segments_1,generation=1}
   [junit4]   2> 2466783 T9151 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2466783 T9151 oass.SolrIndexSearcher.<init> Opening Searcher@5eae006b main
   [junit4]   2> 2466791 T9152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5eae006b main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2466793 T9151 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2466796 T9097 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2466796 T9097 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2466796 T9155 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53965/cza/f collection:collection1 shard:shard1
   [junit4]   2> 2466799 T9155 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2466821 T9155 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2466826 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2466827 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2466827 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2466830 T9155 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2466830 T9155 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4853 name=collection1 org.apache.solr.core.SolrCore@2a9193bb url=http://127.0.0.1:53965/cza/f/collection1 node=127.0.0.1:53965_cza%2Ff C4853_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53965/cza/f, core=collection1, node_name=127.0.0.1:53965_cza%2Ff}
   [junit4]   2> 2466830 T9155 C4853 P53965 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53965/cza/f/collection1/
   [junit4]   2> 2466830 T9155 C4853 P53965 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2466830 T9155 C4853 P53965 oasc.SyncStrategy.syncToMe http://127.0.0.1:53965/cza/f/collection1/ has no replicas
   [junit4]   2> 2466830 T9155 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53965/cza/f/collection1/ shard1
   [junit4]   2> 2466831 T9155 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2466836 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2466849 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2466851 T9150 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> 2466852 T9123 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> 2466853 T9133 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> 2466867 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2466876 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2466992 T9133 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> 2466993 T9123 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> 2466994 T9150 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> 2467027 T9155 oasc.ZkController.register We are http://127.0.0.1:53965/cza/f/collection1/ and leader is http://127.0.0.1:53965/cza/f/collection1/
   [junit4]   2> 2467027 T9155 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53965/cza/f
   [junit4]   2> 2467027 T9155 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2467027 T9155 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 2467027 T9155 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2467032 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2467032 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2467032 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2467037 T9155 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2467041 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2467042 T9124 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:53965/cza/f",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53965_cza%2Ff",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 2467052 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2467168 T9133 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> 2467169 T9123 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> 2467170 T9150 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> 2467471 T9097 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2467478 T9097 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53974
   [junit4]   2> 2467479 T9097 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2467479 T9097 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2467479 T9097 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952
   [junit4]   2> 2467479 T9097 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952\'
   [junit4]   2> 2467516 T9097 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952\solr.xml
   [junit4]   2> 2467578 T9097 oasc.CoreContainer.<init> New CoreContainer 1101156924
   [junit4]   2> 2467580 T9097 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952\]
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2467583 T9097 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2467591 T9097 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2467595 T9097 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2467595 T9097 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2467595 T9097 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53946/solr
   [junit4]   2> 2467595 T9097 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2467599 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2467607 T9167 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c9e5ca8 name:ZooKeeperConnection Watcher:127.0.0.1:53946 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2467608 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2467617 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2467622 T9170 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@447fe3ff name:ZooKeeperConnection Watcher:127.0.0.1:53946/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2467623 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2467631 T9097 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2468717 T9097 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53974_cza%2Ff
   [junit4]   2> 2468719 T9097 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53974_cza%2Ff
   [junit4]   2> 2468725 T9133 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2468725 T9170 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2468725 T9123 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2468725 T9150 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2468737 T9171 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 2468738 T9171 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2468740 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2468740 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2468740 T9171 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2468741 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2468743 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2468745 T9124 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:53974/cza/f",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53974_cza%2Ff",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2468745 T9124 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 2468745 T9124 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2468752 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2468754 T9123 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> 2468755 T9150 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> 2468754 T9133 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> 2468754 T9170 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> 2469819 T9171 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2469819 T9171 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952\collection1
   [junit4]   2> 2469820 T9171 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2469821 T9171 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2469821 T9171 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2469823 T9171 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952\collection1\'
   [junit4]   2> 2469825 T9171 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952/collection1/lib/classes/' to classloader
   [junit4]   2> 2469829 T9171 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952/collection1/lib/README' to classloader
   [junit4]   2> 2469915 T9171 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 2470011 T9171 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2470015 T9171 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2470024 T9171 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2470665 T9171 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2470669 T9171 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2470671 T9171 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2470694 T9171 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2470745 T9171 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2470746 T9171 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ShardSplitTest-jetty2-1388365168952\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty2\
   [junit4]   2> 2470746 T9171 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2368e4dd
   [junit4]   2> 2470747 T9171 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty2\
   [junit4]   2> 2470747 T9171 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty2\index/
   [junit4]   2> 2470747 T9171 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1388365161795\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 2470749 T9171 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty2\index
   [junit4]   2> 2470749 T9171 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=65.3857421875, floorSegmentMB=1.9580078125, forceMergeDeletesPctAllowed=16.3276992108044, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2470749 T9171 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1449d54d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@37450733),segFN=segments_1,generation=1}
   [junit4]   2> 2470749 T9171 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2470753 T9171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2470754 T9171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2470754 T9171 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2470755 T9171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2470755 T9171 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2470755 T9171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2470756 T9171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2470756 T9171 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2470756 T9171 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2470758 T9171 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2470758 T9171 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2470758 T9171 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2470758 T9171 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2470760 T9171 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2470761 T9171 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2470762 T9171 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2470764 T9171 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2470773 T9171 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2470781 T9171 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2470781 T9171 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2470782 T9171 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=59.8974609375, floorSegmentMB=0.859375, forceMergeDeletesPctAllowed=21.36537977082747, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2470784 T9171 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1449d54d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@37450733),segFN=segments_1,generation=1}
   [junit4]   2> 2470784 T9171 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2470784 T9171 oass.SolrIndexSearcher.<init> Opening Searcher@6bafa86c main
   [junit4]   2> 2470788 T9172 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6bafa86c main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2470791 T9171 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2470792 T9097 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2470793 T9097 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2470792 T9175 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53974/cza/f collection:collection1 shard:shard2
   [junit4]   2> 2470796 T9175 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 2470820 T9175 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 2470830 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2470832 T9175 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2470833 T9175 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4854 name=collection1 org.apache.solr.core.SolrCore@3db17f94 url=http://127.0.0.1:53974/cza/f/collection1 node=127.0.0.1:53974_cza%2Ff C4854_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53974/cza/f, core=collection1, node_name=127.0.0.1:53974_cza%2Ff}
   [junit4]   2> 2470833 T9175 C4854 P53974 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53974/cza/f/collection1/
   [junit4]   2> 2470833 T9175 C4854 P53974 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2470833 T9175 C4854 P53974 oasc.SyncStrategy.syncToMe http://127.0.0.1:53974/cza/f/collection1/ has no replicas
   [junit4]   2> 2470833 T9175 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53974/cza/f/collection1/ shard2
   [junit4]   2> 2470833 T9175 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 2470839 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2470854 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2470860 T9150 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> 2470861 T9123 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> 2470862 T9133 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> 2470864 T9170 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> 2470878 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2470886 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2471000 T9123 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> 2471001 T9150 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> 2471001 T9170 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> 2471003 T9133 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> 2471037 T9175 oasc.ZkController.register We are http://127.0.0.1:53974/cza/f/collection1/ and leader is http://127.0.0.1:53974/cza/f/collection1/
   [junit4]   2> 2471037 T9175 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53974/cza/f
   [junit4]   2> 2471037 T9175 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2471037 T9175 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 2471037 T9175 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2471043 T9175 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2471043 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2471044 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2471045 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2471048 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2471049 T9124 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:53974/cza/f",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53974_cza%2Ff",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 2471061 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2471176 T9133 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> 2471176 T9170 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> 2471178 T9150 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> 2471179 T9123 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> 2471549 T9097 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2471556 T9097 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53983
   [junit4]   2> 2471558 T9097 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2471559 T9097 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2471559 T9097 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948
   [junit4]   2> 2471559 T9097 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948\'
   [junit4]   2> 2471605 T9097 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948\solr.xml
   [junit4]   2> 2471664 T9097 oasc.CoreContainer.<init> New CoreContainer 1296038225
   [junit4]   2> 2471664 T9097 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948\]
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2471667 T9097 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2471677 T9097 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2471677 T9097 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2471677 T9097 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2471679 T9097 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53946/solr
   [junit4]   2> 2471679 T9097 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2471684 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2471691 T9187 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1919e2db name:ZooKeeperConnection Watcher:127.0.0.1:53946 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2471692 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2471698 T9097 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2471703 T9190 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b5aa925 name:ZooKeeperConnection Watcher:127.0.0.1:53946/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2471704 T9097 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2471713 T9097 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2472802 T9097 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53983_cza%2Ff
   [junit4]   2> 2472807 T9097 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53983_cza%2Ff
   [junit4]   2> 2472813 T9133 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2472813 T9170 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2472814 T9190 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2472815 T9123 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2472816 T9150 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2472830 T9191 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 2472831 T9191 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2472833 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2472833 T9191 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2472834 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2472834 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2472838 T9124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2472840 T9124 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:53983/cza/f",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53983_cza%2Ff",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2472840 T9124 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 2472840 T9124 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2472845 T9123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2472847 T9123 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2472848 T9190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2472849 T9170 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2472849 T9150 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2472849 T9133 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2473912 T9191 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2473912 T9191 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948\collection1
   [junit4]   2> 2473912 T9191 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2473916 T9191 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2473916 T9191 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2473919 T9191 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948\collection1\'
   [junit4]   2> 2473919 T9191 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948/collection1/lib/classes/' to classloader
   [junit4]   2> 2473922 T9191 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948/collection1/lib/README' to classloader
   [junit4]   2> 2474058 T9191 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 2474138 T9191 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2474142 T9191 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2474154 T9191 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2474820 T9191 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2474824 T9191 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2474825 T9191 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2474833 T9191 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2474885 T9191 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2474886 T9191 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1388365172948\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty3\
   [junit4]   2> 2474886 T9191 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2368e4dd
   [junit4]   2> 2474888 T9191 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty3\
   [junit4]   2> 2474888 T9191 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty3\index/
   [junit4]   2> 2474888 T9191 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1388365161795\jetty3\index' doesn't exist. Creating new index...
   [junit4]   2> 2474889 T9191 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1388365161795/jetty3\index
   [junit4]   2> 2474890 T9191 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=65.3857421875, floorSegmentMB=1.9580078125, forceMergeDeletesPctAllowed=16.3276992108044, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2474890 T9191 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7f905a0e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e430e0c),segFN=segments_1,generation=1}
   [junit4]   2> 2474890 T9191 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2474896 T9191 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2474896 T9191 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2474897 T9191 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2474897 T9191 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2474897 T9191 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2474898 T9191 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2474898 T9191 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2474899 T9191 oasup.UpdateReques

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

g)}, docValues:{}, sim=DefaultSimilarity, locale=ar_SY, timezone=Africa/Conakry
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=2,threads=2,free=28996552,total=217890816
   [junit4]   2> NOTE: All tests run in this JVM: [ShardRoutingCustomTest, ResponseLogComponentTest, DocValuesMultiTest, CurrencyFieldOpenExchangeTest, SuggesterWFSTTest, HdfsRecoveryZkTest, OutputWriterTest, SyncSliceTest, TestUtils, TestRecoveryHdfs, ChaosMonkeyNothingIsSafeTest, AlternateDirectoryTest, ExpressionTest, TermVectorComponentTest, SolrIndexSplitterTest, DocumentAnalysisRequestHandlerTest, TestShardHandlerFactory, TestPHPSerializedResponseWriter, DocumentBuilderTest, ScriptEngineTest, TestLRUCache, DirectSolrConnectionTest, AbstractAnalyticsStatsTest, StatelessScriptUpdateProcessorFactoryTest, HdfsSyncSliceTest, SoftAutoCommitTest, EchoParamsTest, BJQParserTest, TestTrie, TestStressLucene, TestNonNRTOpen, TestLFUCache, SimpleFacetsTest, IndexSchemaTest, SampleTest, TestReload, RegexBoostProcessorTest, UUIDFieldTest, PrimitiveFieldTypeTest, TestQueryTypes, DeleteShardTest, BadIndexSchemaTest, TestCoreContainer, ChaosMonkeySafeLeaderTest, TestLazyCores, TestRealTimeGet, TestWordDelimiterFilterFactory, SynonymTokenizerTest, DistributedQueryElevationComponentTest, ZkControllerTest, ClusterStateTest, TestGroupingSearch, TestSolr4Spatial, SolrCoreTest, ChangedSchemaMergeTest, TestIndexingPerformance, TestExtendedDismaxParser, TestMultiCoreConfBootstrap, TestReloadAndDeleteDocs, PolyFieldTest, TestBinaryResponseWriter, SpellCheckComponentTest, TestZkChroot, DateMathParserTest, TestSolrJ, HdfsCollectionsAPIDistributedZkTest, TestCloudManagedSchema, TestFoldingMultitermQuery, TestUniqueKeyFieldResource, IndexBasedSpellCheckerTest, PreAnalyzedUpdateProcessorTest, TestSort, FieldAnalysisRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TestPseudoReturnFields, ZkSolrClientTest, TestSolrCoreProperties, ZkCLITest, TestOmitPositions, TestAtomicUpdateErrorCases, LoggingHandlerTest, SuggesterTest, TestSchemaSimilarityResource, TestFastOutputStream, TestNumberUtils, RecoveryZkTest, RAMDirectoryFactoryTest, TestPerFieldSimilarity, TestSystemIdResolver, TestDocBasedVersionConstraints, TestMergePolicyConfig, SpatialFilterTest, TestSolrQueryParserDefaultOperatorResource, SliceStateTest, ReturnFieldsTest, ExternalFileFieldSortTest, TestUpdate, OpenCloseCoreStressTest, FieldFacetExtrasTest, AbstractAnalyticsFacetTest, TestStressRecovery, FullSolrCloudDistribCmdsTest, LukeRequestHandlerTest, SuggestComponentTest, TestDFRSimilarityFactory, TestCloudManagedSchemaAddField, HdfsDirectoryTest, TestManagedSchema, HdfsUnloadDistributedZkTest, TestFieldTypeResource, TestReplicationHandler, TestSolrDeletionPolicy1, SortByFunctionTest, TestBM25SimilarityFactory, TestDefaultSimilarityFactory, ModifyConfFileTest, TestRandomMergePolicy, TestQuerySenderNoQuery, BasicDistributedZk2Test, TestPostingsSolrHighlighter, JsonLoaderTest, DeleteReplicaTest, OpenExchangeRatesOrgProviderTest, TestArbitraryIndexDir, DirectSolrSpellCheckerTest, SearchHandlerTest, SliceStateUpdateTest, TestIndexSearcher, SolrTestCaseJ4Test, BadCopyFieldTest, BasicDistributedZkTest, HdfsChaosMonkeySafeLeaderTest, TestRandomFaceting, CoreContainerCoreInitFailuresTest, URLClassifyProcessorTest, TestElisionMultitermQuery, TestCollapseQParserPlugin, TestStressUserVersions, CopyFieldTest, SpellPossibilityIteratorTest, TestSerializedLuceneMatchVersion, MultiTermTest, SignatureUpdateProcessorFactoryTest, ConnectionManagerTest, OverseerCollectionProcessorTest, TestMaxScoreQueryParser, DeleteInactiveReplicaTest, TestDynamicFieldCollectionResource, TestSchemaNameResource, TestAnalyzeInfixSuggestions, MinimalSchemaTest, HdfsBasicDistributedZk2Test, TestHashPartitioner, SolrIndexConfigTest, TestRecovery, TestBinaryField, QueryEqualityTest, TestDistributedSearch, TestCollationFieldDocValues, TestModifyConfFiles, TestIBSimilarityFactory, TestCodecSupport, PreAnalyzedFieldTest, DefaultValueUpdateProcessorTest, UniqFieldsUpdateProcessorFactoryTest, HighlighterConfigTest, TestQuerySenderListener, TestFastWriter, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, OverseerTest, LeaderElectionIntegrationTest, ShardRoutingTest, BasicZkTest, ClusterStateUpdateTest, LeaderElectionTest, TestRandomDVFaceting, AutoCommitTest, TestDistributedGrouping, TestFaceting, DistributedSpellCheckComponentTest, TermVectorComponentDistributedTest, TestStressReorder, TestJoin, TestStressVersions, HardAutoCommitTest, DistributedTermsComponentTest, TestRangeQuery, StatsComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, PeerSyncTest, ConvertedLegacyTest, TestFiltering, TestFunctionQuery, BasicFunctionalityTest, DirectUpdateHandlerTest, TestBadConfig, HighlighterTest, ShowFileRequestHandlerTest, CurrencyFieldXmlFileTest, SimplePostToolTest, TestCoreDiscovery, AnalysisAfterCoreReloadTest, SpellCheckCollatorTest, SuggesterFSTTest, CoreAdminHandlerTest, SolrRequestParserTest, DocValuesTest, SuggesterTSTTest, TestCSVLoader, NoCacheHeaderTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, SolrCoreCheckLockOnStartupTest, FieldMutatingUpdateProcessorTest, DirectUpdateHandlerOptimizeTest, TestRemoteStreaming, DistanceFunctionTest, SolrInfoMBeanTest, XsltUpdateRequestHandlerTest, DebugComponentTest, CacheHeaderTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, TestQueryUtils, StandardRequestHandlerTest, TestWriterPerf, TestReversedWildcardFilterFactory, FileBasedSpellCheckerTest, TermsComponentTest, XmlUpdateRequestHandlerTest, RequestHandlersTest, TestValueSourceCache, MoreLikeThisHandlerTest, RequiredFieldsTest, TestSolrQueryParser, FastVectorHighlighterTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestJmxIntegration, TestCollationField, UpdateRequestProcessorFactoryTest, JSONWriterTest, TestCSVResponseWriter, MBeansHandlerTest, QueryParsingTest, TestAnalyzedSuggestions, BinaryUpdateRequestHandlerTest, TestPartialUpdateDeduplication, PingRequestHandlerTest, CSVRequestHandlerTest, TestComponentsName, SOLR749Test, UpdateParamsTest, TestSolrIndexConfig, BadComponentTest, TestSolrDeletionPolicy2, TestDocSet, TestSearchPerf, NumericFieldsTest, TestConfig, TestFuzzyAnalyzedSuggestions, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, TestPhraseSuggestions, TestCharFilters, TestXIncludeConfig, TestSweetSpotSimilarityFactory, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, LegacyHTMLStripCharFilterTest, TestJmxMonitoredMap, TimeZoneUtilsTest, ResourceLoaderTest, PluginInfoTest, TestFastLRUCache, TestSolrXMLSerializer, PrimUtilsTest, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, DOMUtilTest, TestDocumentBuilder, ZkNodePropsTest, SystemInfoHandlerTest, FileUtilsTest, CircularListTest, TestRTGBase, TestDistributedMissingSort, NoFacetTest, FieldFacetTest, QueryFacetTest, RangeFacetTest, FunctionTest, AliasIntegrationTest, AssignTest, MigrateRouteKeyTest, ShardSplitTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ShardSplitTest -Dtests.seed=F1296F39E51835C6 -Dtests.slow=true -Dtests.locale=ar_SY -Dtests.timezone=Africa/Conakry -Dtests.file.encoding=Cp1252
   [junit4] ERROR   0.00s | ShardSplitTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest: 
   [junit4]    >    1) Thread[id=9379, name=Timer-644, state=WAITING, group=TGRP-ShardSplitTest]
   [junit4]    >         at java.lang.Object.wait(Native Method)
   [junit4]    >         at java.lang.Object.wait(Object.java:503)
   [junit4]    >         at java.util.TimerThread.mainLoop(Timer.java:526)
   [junit4]    >         at java.util.TimerThread.run(Timer.java:505)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([F1296F39E51835C6]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=9379, name=Timer-644, state=WAITING, group=TGRP-ShardSplitTest]
   [junit4]    >         at java.lang.Object.wait(Native Method)
   [junit4]    >         at java.lang.Object.wait(Object.java:503)
   [junit4]    >         at java.util.TimerThread.mainLoop(Timer.java:526)
   [junit4]    >         at java.util.TimerThread.run(Timer.java:505)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([F1296F39E51835C6]:0)
   [junit4] Completed in 117.59s, 1 test, 2 errors <<< FAILURES!

[...truncated 144 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:453: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:433: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:491: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1304: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:937: There were test failures: 358 suites, 1574 tests, 2 suite-level errors, 259 ignored (11 assumptions)

Total time: 70 minutes 20 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b01 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message