You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/28 16:16:26 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b94) - Build #
6351 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/6351/
Java: 32bit/jdk1.8.0-ea-b94 -client -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=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:360) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:939) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:724)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
1) Thread[id=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:360)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:939)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)
at __randomizedtesting.SeedInfo.seed([575283B251B3D6A]: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=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:360) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:939) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:724)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:360)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:939)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)
at __randomizedtesting.SeedInfo.seed([575283B251B3D6A]:0)
Build Log:
[...truncated 9493 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4:junit4] 2> 331433 T2755 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /wcv/n
[junit4:junit4] 2> 331445 T2755 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ShardSplitTest-1372428758045
[junit4:junit4] 2> 331446 T2755 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 331446 T2756 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 331546 T2755 oasc.ZkTestServer.run start zk server on port:33996
[junit4:junit4] 2> 331547 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 331806 T2762 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2819e6 name:ZooKeeperConnection Watcher:127.0.0.1:33996 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 331806 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 331807 T2755 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 331811 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 331812 T2764 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@efff93 name:ZooKeeperConnection Watcher:127.0.0.1:33996/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 331812 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 331812 T2755 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 331814 T2755 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 331816 T2755 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 331817 T2755 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 331819 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 331819 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 331822 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 331823 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 331825 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 331825 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 331827 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 331827 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 331829 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 331829 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 331831 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 331832 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 331833 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 331834 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 331835 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 331836 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 331837 T2755 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 331838 T2755 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 331906 T2755 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 331913 T2755 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40525
[junit4:junit4] 2> 331914 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 331914 T2755 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 331915 T2755 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440
[junit4:junit4] 2> 331915 T2755 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440/solr.xml
[junit4:junit4] 2> 331916 T2755 oasc.CoreContainer.<init> New CoreContainer 1967357
[junit4:junit4] 2> 331917 T2755 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440/'
[junit4:junit4] 2> 331917 T2755 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440/'
[junit4:junit4] 2> 331980 T2755 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 331981 T2755 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 331981 T2755 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 331981 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 331982 T2755 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 331982 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 331983 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 331983 T2755 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 331983 T2755 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 331984 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 331987 T2755 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 331987 T2755 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33996/solr
[junit4:junit4] 2> 331988 T2755 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 331989 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 331990 T2775 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59a66f name:ZooKeeperConnection Watcher:127.0.0.1:33996 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 331990 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 331992 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 331995 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 331996 T2777 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ccb583 name:ZooKeeperConnection Watcher:127.0.0.1:33996/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 331997 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 331998 T2755 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 332000 T2755 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 332002 T2755 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 332003 T2755 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40525_wcv%2Fn
[junit4:junit4] 2> 332004 T2755 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40525_wcv%2Fn
[junit4:junit4] 2> 332006 T2755 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 332009 T2755 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 332011 T2755 oasc.Overseer.start Overseer (id=89943491087433731-127.0.0.1:40525_wcv%2Fn-n_0000000000) starting
[junit4:junit4] 2> 332013 T2755 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 332016 T2779 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 332017 T2755 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 332019 T2755 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 332020 T2755 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 332023 T2778 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 332026 T2780 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 332026 T2780 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 332028 T2780 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4:junit4] 2> 333526 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 333527 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40525_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40525/wcv/n"}
[junit4:junit4] 2> 333528 T2778 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 333528 T2778 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 333531 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 334028 T2780 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4:junit4] 2> 334029 T2780 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440/collection1
[junit4:junit4] 2> 334029 T2780 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 334029 T2780 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 334030 T2780 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 334030 T2780 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440/collection1/'
[junit4:junit4] 2> 334031 T2780 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440/collection1/lib/README' to classloader
[junit4:junit4] 2> 334031 T2780 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 334066 T2780 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 334106 T2780 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 334108 T2780 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 334114 T2780 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 334493 T2780 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 334496 T2780 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 334498 T2780 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 334501 T2780 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 334517 T2780 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 334517 T2780 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1372428758440/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1372428758045/control/data/
[junit4:junit4] 2> 334517 T2780 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@119c41f
[junit4:junit4] 2> 334519 T2780 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/control/data
[junit4:junit4] 2> 334519 T2780 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1372428758045/control/data/index/
[junit4:junit4] 2> 334520 T2780 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1372428758045/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 334520 T2780 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/control/data/index
[junit4:junit4] 2> 334521 T2780 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f92f4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4f47e2),segFN=segments_1,generation=1}
[junit4:junit4] 2> 334522 T2780 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 334523 T2780 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 334523 T2780 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 334524 T2780 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 334524 T2780 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 334525 T2780 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 334525 T2780 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 334525 T2780 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 334526 T2780 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 334526 T2780 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 334528 T2780 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 334530 T2780 oass.SolrIndexSearcher.<init> Opening Searcher@d4fddd main
[junit4:junit4] 2> 334531 T2780 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 334531 T2780 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 334535 T2781 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d4fddd main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 334536 T2780 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 334536 T2780 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40525/wcv/n collection:control_collection shard:shard1
[junit4:junit4] 2> 334536 T2780 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 334541 T2780 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4:junit4] 2> 334543 T2780 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 334543 T2780 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 334543 T2780 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40525/wcv/n/collection1/
[junit4:junit4] 2> 334544 T2780 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 334544 T2780 oasc.SyncStrategy.syncToMe http://127.0.0.1:40525/wcv/n/collection1/ has no replicas
[junit4:junit4] 2> 334544 T2780 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40525/wcv/n/collection1/ shard1
[junit4:junit4] 2> 334544 T2780 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 335033 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 335039 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 335051 T2780 oasc.ZkController.register We are http://127.0.0.1:40525/wcv/n/collection1/ and leader is http://127.0.0.1:40525/wcv/n/collection1/
[junit4:junit4] 2> 335052 T2780 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40525/wcv/n
[junit4:junit4] 2> 335052 T2780 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 335052 T2780 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 335052 T2780 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 335055 T2780 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 335055 T2755 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 335056 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 335056 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 335059 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 335061 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 335063 T2784 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10b964c name:ZooKeeperConnection Watcher:127.0.0.1:33996/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 335063 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 335064 T2755 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 335065 T2755 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 335133 T2755 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 335135 T2755 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55944
[junit4:junit4] 2> 335136 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 335137 T2755 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 335137 T2755 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666
[junit4:junit4] 2> 335137 T2755 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666/solr.xml
[junit4:junit4] 2> 335138 T2755 oasc.CoreContainer.<init> New CoreContainer 7472035
[junit4:junit4] 2> 335138 T2755 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666/'
[junit4:junit4] 2> 335138 T2755 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666/'
[junit4:junit4] 2> 335190 T2755 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 335191 T2755 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 335191 T2755 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 335192 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 335192 T2755 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 335192 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 335193 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 335193 T2755 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 335193 T2755 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 335194 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 335197 T2755 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 335197 T2755 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33996/solr
[junit4:junit4] 2> 335198 T2755 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 335198 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 335200 T2795 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b5d300 name:ZooKeeperConnection Watcher:127.0.0.1:33996 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 335201 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 335202 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 335205 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 335207 T2797 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@225c7a name:ZooKeeperConnection Watcher:127.0.0.1:33996/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 335207 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 335210 T2755 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 336212 T2755 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55944_wcv%2Fn
[junit4:junit4] 2> 336214 T2755 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55944_wcv%2Fn
[junit4:junit4] 2> 336216 T2784 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 336216 T2797 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 336216 T2777 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 336217 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 336221 T2798 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 336221 T2798 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 336222 T2798 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4:junit4] 2> 336543 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 336545 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40525_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40525/wcv/n"}
[junit4:junit4] 2> 336548 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:55944_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55944/wcv/n"}
[junit4:junit4] 2> 336548 T2778 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 336548 T2778 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 336551 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 336551 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 336551 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 337223 T2798 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4:junit4] 2> 337223 T2798 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666/collection1
[junit4:junit4] 2> 337223 T2798 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 337224 T2798 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 337224 T2798 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 337225 T2798 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666/collection1/'
[junit4:junit4] 2> 337226 T2798 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666/collection1/lib/README' to classloader
[junit4:junit4] 2> 337226 T2798 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 337255 T2798 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 337293 T2798 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 337294 T2798 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 337298 T2798 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 337748 T2798 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 337751 T2798 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 337753 T2798 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 337756 T2798 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 337773 T2798 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 337773 T2798 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1372428761666/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty1/
[junit4:junit4] 2> 337773 T2798 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@119c41f
[junit4:junit4] 2> 337774 T2798 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty1
[junit4:junit4] 2> 337775 T2798 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty1/index/
[junit4:junit4] 2> 337775 T2798 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 337776 T2798 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty1/index
[junit4:junit4] 2> 337777 T2798 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5438f1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12a059d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 337777 T2798 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 337779 T2798 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 337779 T2798 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 337780 T2798 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 337780 T2798 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 337781 T2798 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 337781 T2798 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 337781 T2798 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 337782 T2798 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 337782 T2798 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 337784 T2798 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 337787 T2798 oass.SolrIndexSearcher.<init> Opening Searcher@f3d43 main
[junit4:junit4] 2> 337787 T2798 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 337787 T2798 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 337795 T2799 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f3d43 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 337798 T2798 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 337798 T2798 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55944/wcv/n collection:collection1 shard:shard1
[junit4:junit4] 2> 337799 T2798 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 337869 T2798 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4:junit4] 2> 337871 T2798 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 337871 T2798 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 337872 T2798 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55944/wcv/n/collection1/
[junit4:junit4] 2> 337872 T2798 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 337872 T2798 oasc.SyncStrategy.syncToMe http://127.0.0.1:55944/wcv/n/collection1/ has no replicas
[junit4:junit4] 2> 337872 T2798 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55944/wcv/n/collection1/ shard1
[junit4:junit4] 2> 337873 T2798 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 338056 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 338062 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 338062 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 338062 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 338080 T2798 oasc.ZkController.register We are http://127.0.0.1:55944/wcv/n/collection1/ and leader is http://127.0.0.1:55944/wcv/n/collection1/
[junit4:junit4] 2> 338080 T2798 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55944/wcv/n
[junit4:junit4] 2> 338080 T2798 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 338081 T2798 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 338081 T2798 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 338084 T2798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 338086 T2755 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 338087 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 338088 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 338187 T2755 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 338189 T2755 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49506
[junit4:junit4] 2> 338190 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 338190 T2755 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 338190 T2755 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698
[junit4:junit4] 2> 338191 T2755 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698/solr.xml
[junit4:junit4] 2> 338191 T2755 oasc.CoreContainer.<init> New CoreContainer 31672696
[junit4:junit4] 2> 338192 T2755 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698/'
[junit4:junit4] 2> 338192 T2755 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698/'
[junit4:junit4] 2> 338247 T2755 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 338248 T2755 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 338248 T2755 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 338248 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 338249 T2755 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 338249 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 338249 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 338250 T2755 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 338250 T2755 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 338251 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 338254 T2755 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 338254 T2755 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33996/solr
[junit4:junit4] 2> 338255 T2755 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 338255 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 338257 T2811 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d42ae2 name:ZooKeeperConnection Watcher:127.0.0.1:33996 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 338257 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 338259 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 338263 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 338264 T2813 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@199865e name:ZooKeeperConnection Watcher:127.0.0.1:33996/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 338265 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 338268 T2755 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 339271 T2755 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49506_wcv%2Fn
[junit4:junit4] 2> 339272 T2755 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49506_wcv%2Fn
[junit4:junit4] 2> 339274 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 339274 T2777 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 339274 T2813 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 339274 T2784 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 339275 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 339275 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 339276 T2797 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 339389 T2814 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 339389 T2814 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 339391 T2814 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4:junit4] 2> 339566 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 339567 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:55944_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55944/wcv/n"}
[junit4:junit4] 2> 339570 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49506_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49506/wcv/n"}
[junit4:junit4] 2> 339571 T2778 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 339571 T2778 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 339574 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 339574 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 339574 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 339574 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 340391 T2814 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4:junit4] 2> 340392 T2814 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698/collection1
[junit4:junit4] 2> 340392 T2814 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 340393 T2814 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 340393 T2814 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 340394 T2814 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698/collection1/'
[junit4:junit4] 2> 340395 T2814 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698/collection1/lib/README' to classloader
[junit4:junit4] 2> 340396 T2814 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 340444 T2814 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 340518 T2814 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 340519 T2814 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 340525 T2814 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 340909 T2814 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 340912 T2814 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 340913 T2814 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 340916 T2814 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 340932 T2814 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 340932 T2814 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1372428764698/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty2/
[junit4:junit4] 2> 340933 T2814 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@119c41f
[junit4:junit4] 2> 340934 T2814 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty2
[junit4:junit4] 2> 340934 T2814 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty2/index/
[junit4:junit4] 2> 340934 T2814 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 340935 T2814 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty2/index
[junit4:junit4] 2> 340936 T2814 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ca63 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c2f8c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 340937 T2814 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 340938 T2814 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 340939 T2814 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 340939 T2814 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 340940 T2814 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 340941 T2814 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 340941 T2814 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 340941 T2814 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 340942 T2814 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 340942 T2814 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 340944 T2814 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 340947 T2814 oass.SolrIndexSearcher.<init> Opening Searcher@c76384 main
[junit4:junit4] 2> 340947 T2814 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 340947 T2814 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 340953 T2815 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c76384 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 340955 T2814 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 340955 T2814 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49506/wcv/n collection:collection1 shard:shard2
[junit4:junit4] 2> 340956 T2814 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 340960 T2814 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4:junit4] 2> 340961 T2814 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 340961 T2814 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 340962 T2814 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49506/wcv/n/collection1/
[junit4:junit4] 2> 340962 T2814 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 340962 T2814 oasc.SyncStrategy.syncToMe http://127.0.0.1:49506/wcv/n/collection1/ has no replicas
[junit4:junit4] 2> 340962 T2814 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49506/wcv/n/collection1/ shard2
[junit4:junit4] 2> 340963 T2814 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 341079 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 341086 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 341086 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 341086 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 341086 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 341136 T2814 oasc.ZkController.register We are http://127.0.0.1:49506/wcv/n/collection1/ and leader is http://127.0.0.1:49506/wcv/n/collection1/
[junit4:junit4] 2> 341136 T2814 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49506/wcv/n
[junit4:junit4] 2> 341137 T2814 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 341137 T2814 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 341137 T2814 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 341138 T2814 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 341139 T2755 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 341140 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 341140 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 341255 T2755 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 341256 T2755 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40659
[junit4:junit4] 2> 341257 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 341258 T2755 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 341258 T2755 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745
[junit4:junit4] 2> 341258 T2755 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745/solr.xml
[junit4:junit4] 2> 341259 T2755 oasc.CoreContainer.<init> New CoreContainer 20420716
[junit4:junit4] 2> 341259 T2755 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745/'
[junit4:junit4] 2> 341260 T2755 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745/'
[junit4:junit4] 2> 341311 T2755 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 341311 T2755 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 341312 T2755 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 341312 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 341312 T2755 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 341313 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 341313 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 341313 T2755 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 341314 T2755 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 341314 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 341317 T2755 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 341318 T2755 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33996/solr
[junit4:junit4] 2> 341318 T2755 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 341319 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 341320 T2827 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@123316c name:ZooKeeperConnection Watcher:127.0.0.1:33996 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 341321 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 341323 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 341326 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 341327 T2829 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d9e0d name:ZooKeeperConnection Watcher:127.0.0.1:33996/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 341327 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 341330 T2755 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 342332 T2755 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40659_wcv%2Fn
[junit4:junit4] 2> 342333 T2755 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40659_wcv%2Fn
[junit4:junit4] 2> 342335 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 342335 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 342336 T2784 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 342336 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 342336 T2777 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 342337 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 342337 T2829 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 342338 T2813 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 342338 T2797 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 342343 T2830 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 342343 T2830 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 342344 T2830 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4:junit4] 2> 342592 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 342593 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49506_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49506/wcv/n"}
[junit4:junit4] 2> 342595 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40659_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40659/wcv/n"}
[junit4:junit4] 2> 342596 T2778 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 342596 T2778 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 342639 T2829 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 342639 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 342639 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 342639 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 342639 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 343344 T2830 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4:junit4] 2> 343345 T2830 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745/collection1
[junit4:junit4] 2> 343345 T2830 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 343345 T2830 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 343346 T2830 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 343347 T2830 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745/collection1/'
[junit4:junit4] 2> 343347 T2830 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745/collection1/lib/README' to classloader
[junit4:junit4] 2> 343348 T2830 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 343390 T2830 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 343452 T2830 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 343454 T2830 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 343460 T2830 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 343873 T2830 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 343876 T2830 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 343878 T2830 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 343880 T2830 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 343897 T2830 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 343897 T2830 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1372428767745/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty3/
[junit4:junit4] 2> 343897 T2830 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@119c41f
[junit4:junit4] 2> 343899 T2830 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty3
[junit4:junit4] 2> 343899 T2830 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty3/index/
[junit4:junit4] 2> 343899 T2830 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 343900 T2830 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty3/index
[junit4:junit4] 2> 343901 T2830 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4e22e9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@95a84c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 343901 T2830 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 343903 T2830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 343903 T2830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 343904 T2830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 343905 T2830 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 343905 T2830 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 343905 T2830 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 343906 T2830 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 343906 T2830 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 343907 T2830 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 343908 T2830 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 343911 T2830 oass.SolrIndexSearcher.<init> Opening Searcher@108dde0 main
[junit4:junit4] 2> 343912 T2830 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 343912 T2830 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 343917 T2831 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@108dde0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 343920 T2830 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 343920 T2830 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40659/wcv/n collection:collection1 shard:shard1
[junit4:junit4] 2> 343922 T2830 oasc.ZkController.register We are http://127.0.0.1:40659/wcv/n/collection1/ and leader is http://127.0.0.1:55944/wcv/n/collection1/
[junit4:junit4] 2> 343922 T2830 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40659/wcv/n
[junit4:junit4] 2> 343922 T2830 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 343923 T2830 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C775 name=collection1 org.apache.solr.core.SolrCore@6f4a31 url=http://127.0.0.1:40659/wcv/n/collection1 node=127.0.0.1:40659_wcv%2Fn C775_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:40659_wcv%2Fn, base_url=http://127.0.0.1:40659/wcv/n}
[junit4:junit4] 2> 343923 T2832 C775 P40659 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 343923 T2830 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 343923 T2832 C775 P40659 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 343924 T2832 C775 P40659 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 343924 T2832 C775 P40659 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 343938 T2755 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 343938 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> ASYNC NEW_CORE C776 name=collection1 org.apache.solr.core.SolrCore@6f4a31 url=http://127.0.0.1:40659/wcv/n/collection1 node=127.0.0.1:40659_wcv%2Fn C776_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:40659_wcv%2Fn, base_url=http://127.0.0.1:40659/wcv/n}
[junit4:junit4] 2> 343938 T2832 C776 P40659 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 343939 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 343943 T2790 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 344013 T2755 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 344015 T2755 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42486
[junit4:junit4] 2> 344016 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 344017 T2755 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 344017 T2755 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542
[junit4:junit4] 2> 344017 T2755 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542/solr.xml
[junit4:junit4] 2> 344018 T2755 oasc.CoreContainer.<init> New CoreContainer 17838386
[junit4:junit4] 2> 344018 T2755 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542/'
[junit4:junit4] 2> 344018 T2755 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542/'
[junit4:junit4] 2> 344069 T2755 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 344070 T2755 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 344070 T2755 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 344070 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 344071 T2755 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 344071 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 344071 T2755 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 344072 T2755 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 344072 T2755 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 344072 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 344075 T2755 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 344076 T2755 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33996/solr
[junit4:junit4] 2> 344076 T2755 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 344077 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 344079 T2844 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8ccd77 name:ZooKeeperConnection Watcher:127.0.0.1:33996 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 344079 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 344081 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 344084 T2755 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 344085 T2846 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b37f4c name:ZooKeeperConnection Watcher:127.0.0.1:33996/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 344085 T2755 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 344088 T2755 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 344144 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 344145 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40659_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40659/wcv/n"}
[junit4:junit4] 2> 344155 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 344156 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 344156 T2846 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 344156 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 344155 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 344155 T2829 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 344944 T2790 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 344944 T2790 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node3&state=recovering&nodeName=127.0.0.1:40659_wcv%252Fn&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 345091 T2755 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42486_wcv%2Fn
[junit4:junit4] 2> 345092 T2755 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42486_wcv%2Fn
[junit4:junit4] 2> 345094 T2829 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 345094 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 345094 T2846 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 345094 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 345094 T2777 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 345094 T2784 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 345095 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 345095 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 345096 T2829 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 345096 T2797 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 345096 T2813 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 345097 T2846 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 345100 T2847 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 345101 T2847 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 345102 T2847 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4:junit4] 2> 345661 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 345662 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42486_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42486/wcv/n"}
[junit4:junit4] 2> 345662 T2778 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 345662 T2778 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 345665 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 345666 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 345666 T2846 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 345666 T2829 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 345665 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 345665 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 346102 T2847 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4:junit4] 2> 346103 T2847 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542/collection1
[junit4:junit4] 2> 346103 T2847 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 346103 T2847 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 346104 T2847 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 346105 T2847 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542/collection1/'
[junit4:junit4] 2> 346105 T2847 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542/collection1/lib/README' to classloader
[junit4:junit4] 2> 346106 T2847 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 346137 T2847 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 346176 T2847 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 346177 T2847 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 346181 T2847 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 346596 T2847 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 346599 T2847 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 346600 T2847 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 346604 T2847 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 346621 T2847 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 346622 T2847 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1372428770542/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty4/
[junit4:junit4] 2> 346622 T2847 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@119c41f
[junit4:junit4] 2> 346623 T2847 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty4
[junit4:junit4] 2> 346623 T2847 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty4/index/
[junit4:junit4] 2> 346623 T2847 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 346624 T2847 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1372428758045/jetty4/index
[junit4:junit4] 2> 346625 T2847 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1267457 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e37219),segFN=segments_1,generation=1}
[junit4:junit4] 2> 346626 T2847 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 346627 T2847 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 346628 T2847 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 346628 T2847 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 346629 T2847 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 346629 T2847 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 346630 T2847 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 346630 T2847 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 346631 T2847 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 346631 T2847 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 346632 T2847 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 346635 T2847 oass.SolrIndexSearcher.<init> Opening Searcher@9ef68b main
[junit4:junit4] 2> 346636 T2847 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 346636 T2847 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 346642 T2848 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9ef68b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 346644 T2847 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 346644 T2847 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42486/wcv/n collection:collection1 shard:shard2
[junit4:junit4] 2> 346648 T2847 oasc.ZkController.register We are http://127.0.0.1:42486/wcv/n/collection1/ and leader is http://127.0.0.1:49506/wcv/n/collection1/
[junit4:junit4] 2> 346648 T2847 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42486/wcv/n
[junit4:junit4] 2> 346648 T2847 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 346648 T2847 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C777 name=collection1 org.apache.solr.core.SolrCore@14b668c url=http://127.0.0.1:42486/wcv/n/collection1 node=127.0.0.1:42486_wcv%2Fn C777_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:42486_wcv%2Fn, base_url=http://127.0.0.1:42486/wcv/n}
[junit4:junit4] 2> 346649 T2849 C777 P42486 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 346649 T2847 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 346649 T2849 C777 P42486 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 346650 T2849 C777 P42486 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 346650 T2849 C777 P42486 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 346650 T2755 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 346651 T2755 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 346651 T2755 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 346655 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 346656 T2849 C777 P42486 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 346657 T2755 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 346657 T2755 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 346658 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 346660 T2809 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> ASYNC NEW_CORE C778 name=collection1 org.apache.solr.core.SolrCore@6f4a31 url=http://127.0.0.1:40659/wcv/n/collection1 node=127.0.0.1:40659_wcv%2Fn C778_STATE=coll:collection1 core:collection1 props:{state=recovering, core=collection1, node_name=127.0.0.1:40659_wcv%2Fn, base_url=http://127.0.0.1:40659/wcv/n}
[junit4:junit4] 2> 346945 T2832 C778 P40659 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:55944/wcv/n/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 346946 T2832 C778 P40659 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:40659/wcv/n START replicas=[http://127.0.0.1:55944/wcv/n/collection1/] nUpdates=100
[junit4:junit4] 2> 346946 T2832 C778 P40659 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 346947 T2832 C778 P40659 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 346947 T2832 C778 P40659 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 346947 T2832 C778 P40659 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 346947 T2832 C778 P40659 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 346948 T2832 C778 P40659 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:55944/wcv/n/collection1/. core=collection1
[junit4:junit4] 2> 346948 T2832 C778 P40659 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C779 name=collection1 org.apache.solr.core.SolrCore@f3a7ee url=http://127.0.0.1:55944/wcv/n/collection1 node=127.0.0.1:55944_wcv%2Fn C779_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:55944_wcv%2Fn, base_url=http://127.0.0.1:55944/wcv/n, leader=true}
[junit4:junit4] 2> 346953 T2790 C779 P55944 oasc.SolrCore.execute [collection1] webapp=/wcv/n path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 346958 T2793 C779 P55944 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 346960 T2793 C779 P55944 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5438f1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12a059d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 346961 T2793 C779 P55944 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 346962 T2793 C779 P55944 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 346962 T2793 C779 P55944 oass.SolrIndexSearcher.<init> Opening Searcher@1c485f3 realtime
[junit4:junit4] 2> 346963 T2793 C779 P55944 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 346963 T2793 C779 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 346964 T2832 C778 P40659 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 346965 T2832 C778 P40659 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 346970 T2792 C779 P55944 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 346970 T2792 C779 P55944 oasc.SolrCore.execute [collection1] webapp=/wcv/n path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=4
[junit4:junit4] 2> 346971 T2832 C778 P40659 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 346971 T2832 C778 P40659 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 346972 T2832 C778 P40659 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 346972 T2832 C778 P40659 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 346974 T2832 C778 P40659 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 347170 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 347171 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42486_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42486/wcv/n"}
[junit4:junit4] 2> 347173 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:40659_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:40659/wcv/n"}
[junit4:junit4] 2> 347176 T2846 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 347176 T2829 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 347176 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 347176 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 347176 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 347176 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 347660 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 347661 T2809 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 347661 T2809 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node4&state=recovering&nodeName=127.0.0.1:42486_wcv%252Fn&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 348661 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C777_STATE=coll:collection1 core:collection1 props:{state=recovering, core=collection1, node_name=127.0.0.1:42486_wcv%2Fn, base_url=http://127.0.0.1:42486/wcv/n}
[junit4:junit4] 2> 349662 T2849 C777 P42486 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:49506/wcv/n/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 349663 T2849 C777 P42486 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:42486/wcv/n START replicas=[http://127.0.0.1:49506/wcv/n/collection1/] nUpdates=100
[junit4:junit4] 2> 349663 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 349663 T2849 C777 P42486 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 349664 T2849 C777 P42486 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 349664 T2849 C777 P42486 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 349664 T2849 C777 P42486 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 349664 T2849 C777 P42486 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 349664 T2849 C777 P42486 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:49506/wcv/n/collection1/. core=collection1
[junit4:junit4] 2> 349665 T2849 C777 P42486 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C780 name=collection1 org.apache.solr.core.SolrCore@8fd0dc url=http://127.0.0.1:49506/wcv/n/collection1 node=127.0.0.1:49506_wcv%2Fn C780_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:49506_wcv%2Fn, base_url=http://127.0.0.1:49506/wcv/n, leader=true}
[junit4:junit4] 2> 349672 T2808 C780 P49506 oasc.SolrCore.execute [collection1] webapp=/wcv/n path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 349675 T2807 C780 P49506 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 349677 T2807 C780 P49506 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ca63 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c2f8c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 349678 T2807 C780 P49506 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 349679 T2807 C780 P49506 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 349679 T2807 C780 P49506 oass.SolrIndexSearcher.<init> Opening Searcher@13baa0d realtime
[junit4:junit4] 2> 349680 T2807 C780 P49506 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 349680 T2807 C780 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 349681 T2849 C777 P42486 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 349681 T2849 C777 P42486 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 349683 T2808 C780 P49506 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 349684 T2808 C780 P49506 oasc.SolrCore.execute [collection1] webapp=/wcv/n path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 349685 T2849 C777 P42486 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 349685 T2849 C777 P42486 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 349685 T2849 C777 P42486 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 349685 T2849 C777 P42486 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 349686 T2849 C777 P42486 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 350184 T2778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 350184 T2778 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"core_node4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42486_wcv%2Fn",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42486/wcv/n"}
[junit4:junit4] 2> 350208 T2777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 350209 T2784 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 350209 T2829 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 350209 T2797 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 350209 T2813 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 350208 T2846 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 350665 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 350666 T2755 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C781 name=collection1 org.apache.solr.core.SolrCore@f83ec1 url=http://127.0.0.1:40525/wcv/n/collection1 node=127.0.0.1:40525_wcv%2Fn C781_STATE=coll:control_collection core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:40525_wcv%2Fn, base_url=http://127.0.0.1:40525/wcv/n, leader=true}
[junit4:junit4] 2> 350672 T2771 C781 P40525 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 350674 T2771 C781 P40525 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f92f4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4f47e2),segFN=segments_1,generation=1}
[junit4:junit4] 2> 350674 T2771 C781 P40525 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 350675 T2771 C781 P40525 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 350675 T2771 C781 P40525 oass.SolrIndexSearcher.<init> Opening Searcher@17a5633 main
[junit4:junit4] 2> 350676 T2771 C781 P40525 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 350691 T2781 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17a5633 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4] 2> ASYNC NEW_CORE C782 name=collection1 org.apache.solr.core.SolrCore@f83ec1 url=http://127.0.0.1:40525/wcv/n/collection1 node=127.0.0.1:40525_wcv%2Fn C782_STATE=coll:control_collection core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:40525_wcv%2Fn, base_url=http://127.0.0.1:40525/wcv/n, leader=true}
[junit4:junit4] 2> 350692 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 21
[junit4:junit4] 2> ASYNC NEW_CORE C783 name=collection1 org.apache.solr.core.SolrCore@8fd0dc url=http://127.0.0.1:49506/wcv/n/collection1 node=127.0.0.1:49506_wcv%2Fn C783_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:49506_wcv%2Fn, base_url=http://127.0.0.1:49506/wcv/n, leader=true}
[junit4:junit4] 2> 350696 T2808 C783 P49506 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:55944/wcv/n/collection1/, StdNode: http://127.0.0.1:40659/wcv/n/collection1/, StdNode: http://127.0.0.1:49506/wcv/n/collection1/, StdNode: http://127.0.0.1:42486/wcv/n/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> ASYNC NEW_CORE C784 name=collection1 org.apache.solr.core.SolrCore@f3a7ee url=http://127.0.0.1:55944/wcv/n/collection1 node=127.0.0.1:55944_wcv%2Fn C784_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:55944_wcv%2Fn, base_url=http://127.0.0.1:55944/wcv/n, leader=true}
[junit4:junit4] 2> 350698 T2792 C784 P55944 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 350698 T2792 C784 P55944 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 350699 T2792 C784 P55944 oass.SolrIndexSearcher.<init> Opening Searcher@1936ec4 main
[junit4:junit4] 2> 350699 T2792 C784 P55944 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 350700 T2799 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1936ec4 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4] 2> 350701 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 3
[junit4:junit4] 2> 350703 T2806 C783 P49506 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 350704 T2806 C783 P49506 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 350704 T2806 C783 P49506 oass.SolrIndexSearcher.<init> Opening Searcher@15fdf46 main
[junit4:junit4] 2> 350704 T2806 C783 P49506 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 350706 T2815 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15fdf46 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4] 2> 350706 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 3
[junit4:junit4] 2> ASYNC NEW_CORE C785 name=collection1 org.apache.solr.core.SolrCore@14b668c url=http://127.0.0.1:42486/wcv/n/collection1 node=127.0.0.1:42486_wcv%2Fn C785_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:42486_wcv%2Fn, base_url=http://127.0.0.1:42486/wcv/n}
[junit4:junit4] 2> 350708 T2839 C785 P42486 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 350710 T2839 C785 P42486 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1267457 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e37219),segFN=segments_1,generation=1}
[junit4:junit4] 2> 350711 T2839 C785 P42486 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> ASYNC NEW_CORE C786 name=collection1 org.apache.solr.core.SolrCore@6f4a31 url=http://127.0.0.1:40659/wcv/n/collection1 node=127.0.0.1:40659_wcv%2Fn C786_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:40659_wcv%2Fn, base_url=http://127.0.0.1:40659/wcv/n}
[junit4:junit4] 2> 350711 T2822 C786 P40659 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 350711 T2839 C785 P42486 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 350712 T2839 C785 P42486 oass.SolrIndexSearcher.<init> Opening Searcher@10535f5 main
[junit4:junit4] 2> 350713 T2822 C786 P40659 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4e22e9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@95a84c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 350713 T2839 C785 P42486 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 350713 T2822 C786 P40659 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 350714 T2822 C786 P40659 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 350715 T2848 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10535f5 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4] 2> 350715 T2822 C786 P40659 oass.SolrIndexSearcher.<init> Opening Searcher@da2a0c main
[junit4:junit4] 2> 350716 T2822 C786 P40659 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 350716 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4] 2> 350717 T2831 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@da2a0c main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4] 2> 350717 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4] 2> 350718 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 22
[junit4:junit4] 2> 350719 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 350726 T2793 C784 P55944 oasc.SolrCore.execute [collection1] webapp=/wcv/n path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 350729 T2824 C786 P40659 oasc.SolrCore.execute [collection1] webapp=/wcv/n path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 350731 T2807 C783 P49506 oasc.SolrCore.execute [collection1] webapp=/wcv/n path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 350733 T2842 C785 P42486 oasc.SolrCore.execute [collection1] webapp=/wcv/n path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1
[junit4:junit4] 2> 352739 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1439095879723122688)} 0 2
[junit4:junit4] 2> 352746 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={update.distrib=FROMLEADER&_version_=-1439095879726268416&update.from=http://127.0.0.1:55944/wcv/n/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1439095879726268416)} 0 2
[junit4:junit4] 2> 352748 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={update.distrib=FROMLEADER&_version_=-1439095879729414144&update.from=http://127.0.0.1:49506/wcv/n/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1439095879729414144)} 0 1
[junit4:junit4] 2> 352749 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1439095879729414144)} 0 5
[junit4:junit4] 2> 352750 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1439095879726268416)} 0 9
[junit4:junit4] 2> 352753 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[a!0 (1439095879737802752)]} 0 1
[junit4:junit4] 2> 352758 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!0 (1439095879740948480)]} 0 0
[junit4:junit4] 2> 352759 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[a!0 (1439095879740948480)]} 0 4
[junit4:junit4] 2> 352761 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[b!1 (1439095879747239936)]} 0 0
[junit4:junit4] 2> 352769 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!1 (1439095879752482816)]} 0 1
[junit4:junit4] 2> 352770 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[b!1 (1439095879752482816)]} 0 4
[junit4:junit4] 2> 352770 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[b!1]} 0 6
[junit4:junit4] 2> 352773 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[c!2 (1439095879759822848)]} 0 0
[junit4:junit4] 2> 352778 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!2 (1439095879762968576)]} 0 0
[junit4:junit4] 2> 352779 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[c!2 (1439095879762968576)]} 0 3
[junit4:junit4] 2> 352781 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[d!3 (1439095879768211456)]} 0 0
[junit4:junit4] 2> 352786 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!3 (1439095879771357184)]} 0 0
[junit4:junit4] 2> 352787 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[d!3 (1439095879771357184)]} 0 3
[junit4:junit4] 2> 352789 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[e!4 (1439095879776600064)]} 0 0
[junit4:junit4] 2> 352796 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!4 (1439095879781842944)]} 0 1
[junit4:junit4] 2> 352797 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!4 (1439095879781842944)]} 0 4
[junit4:junit4] 2> 352797 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[e!4]} 0 5
[junit4:junit4] 2> 352800 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[f!5 (1439095879787085824)]} 0 1
[junit4:junit4] 2> 352804 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!5 (1439095879790231552)]} 0 0
[junit4:junit4] 2> 352805 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[f!5 (1439095879790231552)]} 0 3
[junit4:junit4] 2> 352808 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[g!6 (1439095879796523008)]} 0 0
[junit4:junit4] 2> 352815 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!6 (1439095879800717312)]} 0 0
[junit4:junit4] 2> 352816 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!6 (1439095879800717312)]} 0 4
[junit4:junit4] 2> 352816 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[g!6]} 0 6
[junit4:junit4] 2> 352819 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[h!7 (1439095879808057344)]} 0 0
[junit4:junit4] 2> 352824 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!7 (1439095879811203072)]} 0 0
[junit4:junit4] 2> 352825 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[h!7 (1439095879811203072)]} 0 3
[junit4:junit4] 2> 352828 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[i!8 (1439095879817494528)]} 0 0
[junit4:junit4] 2> 352838 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!8 (1439095879824834560)]} 0 1
[junit4:junit4] 2> 352838 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!8 (1439095879824834560)]} 0 3
[junit4:junit4] 2> 352839 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[i!8]} 0 8
[junit4:junit4] 2> 352842 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[j!9 (1439095879832174592)]} 0 1
[junit4:junit4] 2> 352849 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!9 (1439095879836368896)]} 0 1
[junit4:junit4] 2> 352849 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[j!9 (1439095879836368896)]} 0 3
[junit4:junit4] 2> 352850 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[j!9]} 0 6
[junit4:junit4] 2> 352853 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[k!10 (1439095879843708928)]} 0 1
[junit4:junit4] 2> 352860 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!10 (1439095879848951808)]} 0 0
[junit4:junit4] 2> 352861 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!10 (1439095879848951808)]} 0 3
[junit4:junit4] 2> 352862 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[k!10]} 0 6
[junit4:junit4] 2> 352864 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[l!11 (1439095879855243264)]} 0 0
[junit4:junit4] 2> 352870 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!11 (1439095879858388992)]} 0 1
[junit4:junit4] 2> 352870 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[l!11 (1439095879858388992)]} 0 3
[junit4:junit4] 2> 352873 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[m!12 (1439095879864680448)]} 0 1
[junit4:junit4] 2> 352880 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!12 (1439095879868874752)]} 0 1
[junit4:junit4] 2> 352881 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[m!12 (1439095879868874752)]} 0 4
[junit4:junit4] 2> 352881 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[m!12]} 0 6
[junit4:junit4] 2> 352885 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[n!13 (1439095879876214784)]} 0 1
[junit4:junit4] 2> 352890 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!13 (1439095879880409088)]} 0 0
[junit4:junit4] 2> 352891 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[n!13 (1439095879880409088)]} 0 4
[junit4:junit4] 2> 352894 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[o!14 (1439095879886700544)]} 0 1
[junit4:junit4] 2> 352899 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!14 (1439095879889846272)]} 0 0
[junit4:junit4] 2> 352900 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[o!14 (1439095879889846272)]} 0 4
[junit4:junit4] 2> 352902 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[p!15 (1439095879895089152)]} 0 0
[junit4:junit4] 2> 352907 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!15 (1439095879898234880)]} 0 0
[junit4:junit4] 2> 352908 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[p!15 (1439095879898234880)]} 0 3
[junit4:junit4] 2> 352911 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[q!16 (1439095879904526336)]} 0 0
[junit4:junit4] 2> 352918 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!16 (1439095879908720640)]} 0 1
[junit4:junit4] 2> 352919 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[q!16 (1439095879908720640)]} 0 4
[junit4:junit4] 2> 352919 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[q!16]} 0 6
[junit4:junit4] 2> 352922 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[r!17 (1439095879916060672)]} 0 0
[junit4:junit4] 2> 352927 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!17 (1439095879919206400)]} 0 0
[junit4:junit4] 2> 352929 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[r!17 (1439095879919206400)]} 0 4
[junit4:junit4] 2> 352931 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[s!18 (1439095879925497856)]} 0 0
[junit4:junit4] 2> 352938 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!18 (1439095879930740736)]} 0 0
[junit4:junit4] 2> 352939 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[s!18 (1439095879930740736)]} 0 4
[junit4:junit4] 2> 352940 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[s!18]} 0 7
[junit4:junit4] 2> 352943 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[t!19 (1439095879937032192)]} 0 1
[junit4:junit4] 2> 352948 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!19 (1439095879940177920)]} 0 1
[junit4:junit4] 2> 352948 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[t!19 (1439095879940177920)]} 0 3
[junit4:junit4] 2> 352951 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[u!20 (1439095879946469376)]} 0 0
[junit4:junit4] 2> 352956 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!20 (1439095879948566528)]} 0 1
[junit4:junit4] 2> 352957 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[u!20 (1439095879948566528)]} 0 4
[junit4:junit4] 2> 352959 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[v!21 (1439095879954857984)]} 0 0
[junit4:junit4] 2> 352965 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!21 (1439095879959052288)]} 0 0
[junit4:junit4] 2> 352966 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[v!21 (1439095879959052288)]} 0 3
[junit4:junit4] 2> 352967 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[v!21]} 0 6
[junit4:junit4] 2> 352970 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[w!22 (1439095879965343744)]} 0 1
[junit4:junit4] 2> 352976 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!22 (1439095879970586624)]} 0 0
[junit4:junit4] 2> 352977 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[w!22 (1439095879970586624)]} 0 3
[junit4:junit4] 2> 352977 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[w!22]} 0 5
[junit4:junit4] 2> 352980 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[x!23 (1439095879976878080)]} 0 1
[junit4:junit4] 2> 352985 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!23 (1439095879978975232)]} 0 1
[junit4:junit4] 2> 352985 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[x!23 (1439095879978975232)]} 0 3
[junit4:junit4] 2> 352988 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[y!24 (1439095879985266688)]} 0 1
[junit4:junit4] 2> 352992 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!24 (1439095879987363840)]} 0 0
[junit4:junit4] 2> 352993 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[y!24 (1439095879987363840)]} 0 3
[junit4:junit4] 2> 352996 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[z!25 (1439095879992606720)]} 0 1
[junit4:junit4] 2> 353000 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!25 (1439095879995752448)]} 0 0
[junit4:junit4] 2> 353001 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[z!25 (1439095879995752448)]} 0 3
[junit4:junit4] 2> 353004 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[a!26 (1439095880000995328)]} 0 1
[junit4:junit4] 2> 353010 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!26 (1439095880006238208)]} 0 0
[junit4:junit4] 2> 353011 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!26 (1439095880006238208)]} 0 3
[junit4:junit4] 2> 353012 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[a!26]} 0 6
[junit4:junit4] 2> 353015 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[b!27 (1439095880012529664)]} 0 1
[junit4:junit4] 2> 353022 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!27 (1439095880017772544)]} 0 1
[junit4:junit4] 2> 353022 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[b!27 (1439095880017772544)]} 0 3
[junit4:junit4] 2> 353023 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[b!27]} 0 6
[junit4:junit4] 2> 353026 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[c!28 (1439095880024064000)]} 0 1
[junit4:junit4] 2> 353030 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!28 (1439095880027209728)]} 0 0
[junit4:junit4] 2> 353031 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[c!28 (1439095880027209728)]} 0 3
[junit4:junit4] 2> 353033 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[d!29 (1439095880032452608)]} 0 0
[junit4:junit4] 2> 353040 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!29 (1439095880037695488)]} 0 0
[junit4:junit4] 2> 353041 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!29 (1439095880037695488)]} 0 3
[junit4:junit4] 2> 353041 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[d!29]} 0 5
[junit4:junit4] 2> 353044 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[e!30 (1439095880043986944)]} 0 0
[junit4:junit4] 2> 353051 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!30 (1439095880049229824)]} 0 0
[junit4:junit4] 2> 353052 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!30 (1439095880049229824)]} 0 3
[junit4:junit4] 2> 353052 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[e!30]} 0 5
[junit4:junit4] 2> 353055 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[f!31 (1439095880054472704)]} 0 1
[junit4:junit4] 2> 353061 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!31 (1439095880059715584)]} 0 0
[junit4:junit4] 2> 353062 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[f!31 (1439095880059715584)]} 0 3
[junit4:junit4] 2> 353063 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[f!31]} 0 6
[junit4:junit4] 2> 353065 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[g!32 (1439095880066007040)]} 0 0
[junit4:junit4] 2> 353070 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!32 (1439095880069152768)]} 0 0
[junit4:junit4] 2> 353071 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[g!32 (1439095880069152768)]} 0 4
[junit4:junit4] 2> 353074 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[h!33 (1439095880075444224)]} 0 0
[junit4:junit4] 2> 353081 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!33 (1439095880080687104)]} 0 0
[junit4:junit4] 2> 353082 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[h!33 (1439095880080687104)]} 0 3
[junit4:junit4] 2> 353083 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[h!33]} 0 6
[junit4:junit4] 2> 353086 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[i!34 (1439095880086978560)]} 0 1
[junit4:junit4] 2> 353093 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!34 (1439095880092221440)]} 0 1
[junit4:junit4] 2> 353093 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!34 (1439095880092221440)]} 0 3
[junit4:junit4] 2> 353094 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[i!34]} 0 6
[junit4:junit4] 2> 353097 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[j!35 (1439095880099561472)]} 0 1
[junit4:junit4] 2> 353104 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!35 (1439095880104804352)]} 0 1
[junit4:junit4] 2> 353105 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[j!35 (1439095880104804352)]} 0 4
[junit4:junit4] 2> 353105 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[j!35]} 0 5
[junit4:junit4] 2> 353108 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[k!36 (1439095880111095808)]} 0 1
[junit4:junit4] 2> 353115 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!36 (1439095880115290112)]} 0 1
[junit4:junit4] 2> 353115 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!36 (1439095880115290112)]} 0 3
[junit4:junit4] 2> 353116 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[k!36]} 0 6
[junit4:junit4] 2> 353119 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[l!37 (1439095880122630144)]} 0 0
[junit4:junit4] 2> 353124 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!37 (1439095880125775872)]} 0 0
[junit4:junit4] 2> 353125 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[l!37 (1439095880125775872)]} 0 3
[junit4:junit4] 2> 353127 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[m!38 (1439095880131018752)]} 0 0
[junit4:junit4] 2> 353132 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!38 (1439095880134164480)]} 0 1
[junit4:junit4] 2> 353132 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[m!38 (1439095880134164480)]} 0 2
[junit4:junit4] 2> 353135 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[n!39 (1439095880139407360)]} 0 0
[junit4:junit4] 2> 353140 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!39 (1439095880142553088)]} 0 0
[junit4:junit4] 2> 353141 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[n!39 (1439095880142553088)]} 0 3
[junit4:junit4] 2> 353144 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[o!40 (1439095880148844544)]} 0 1
[junit4:junit4] 2> 353149 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!40 (1439095880150941696)]} 0 1
[junit4:junit4] 2> 353149 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[o!40 (1439095880150941696)]} 0 3
[junit4:junit4] 2> 353152 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[p!41 (1439095880157233152)]} 0 0
[junit4:junit4] 2> 353159 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!41 (1439095880162476032)]} 0 0
[junit4:junit4] 2> 353160 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[p!41 (1439095880162476032)]} 0 3
[junit4:junit4] 2> 353160 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[p!41]} 0 5
[junit4:junit4] 2> 353163 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[q!42 (1439095880168767488)]} 0 0
[junit4:junit4] 2> 353170 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!42 (1439095880172961792)]} 0 0
[junit4:junit4] 2> 353171 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[q!42 (1439095880172961792)]} 0 4
[junit4:junit4] 2> 353171 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[q!42]} 0 6
[junit4:junit4] 2> 353174 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[r!43 (1439095880180301824)]} 0 0
[junit4:junit4] 2> 353181 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!43 (1439095880185544704)]} 0 1
[junit4:junit4] 2> 353182 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[r!43 (1439095880185544704)]} 0 4
[junit4:junit4] 2> 353182 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[r!43]} 0 6
[junit4:junit4] 2> 353185 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[s!44 (1439095880191836160)]} 0 0
[junit4:junit4] 2> 353191 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!44 (1439095880196030464)]} 0 0
[junit4:junit4] 2> 353192 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[s!44 (1439095880196030464)]} 0 3
[junit4:junit4] 2> 353193 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[s!44]} 0 6
[junit4:junit4] 2> 353195 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[t!45 (1439095880202321920)]} 0 0
[junit4:junit4] 2> 353200 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!45 (1439095880205467648)]} 0 0
[junit4:junit4] 2> 353201 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[t!45 (1439095880205467648)]} 0 3
[junit4:junit4] 2> 353203 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[u!46 (1439095880210710528)]} 0 0
[junit4:junit4] 2> 353208 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!46 (1439095880213856256)]} 0 0
[junit4:junit4] 2> 353209 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[u!46 (1439095880213856256)]} 0 3
[junit4:junit4] 2> 353211 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[v!47 (1439095880219099136)]} 0 0
[junit4:junit4] 2> 353217 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!47 (1439095880222244864)]} 0 1
[junit4:junit4] 2> 353218 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[v!47 (1439095880222244864)]} 0 4
[junit4:junit4] 2> 353220 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[w!48 (1439095880228536320)]} 0 0
[junit4:junit4] 2> 353227 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!48 (1439095880233779200)]} 0 0
[junit4:junit4] 2> 353228 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[w!48 (1439095880233779200)]} 0 3
[junit4:junit4] 2> 353229 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[w!48]} 0 6
[junit4:junit4] 2> 353231 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[x!49 (1439095880240070656)]} 0 0
[junit4:junit4] 2> 353238 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!49 (1439095880245313536)]} 0 0
[junit4:junit4] 2> 353239 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[x!49 (1439095880245313536)]} 0 3
[junit4:junit4] 2> 353239 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[x!49]} 0 5
[junit4:junit4] 2> 353242 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[y!50 (1439095880250556416)]} 0 1
[junit4:junit4] 2> 353248 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!50 (1439095880255799296)]} 0 0
[junit4:junit4] 2> 353249 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[y!50 (1439095880255799296)]} 0 3
[junit4:junit4] 2> 353250 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[y!50]} 0 6
[junit4:junit4] 2> 353253 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[z!51 (1439095880262090752)]} 0 1
[junit4:junit4] 2> 353258 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!51 (1439095880265236480)]} 0 1
[junit4:junit4] 2> 353258 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[z!51 (1439095880265236480)]} 0 3
[junit4:junit4] 2> 353261 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[a!52 (1439095880271527936)]} 0 0
[junit4:junit4] 2> 353267 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!52 (1439095880274673664)]} 0 1
[junit4:junit4] 2> 353268 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[a!52 (1439095880274673664)]} 0 4
[junit4:junit4] 2> 353271 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[b!53 (1439095880280965120)]} 0 1
[junit4:junit4] 2> 353275 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!53 (1439095880284110848)]} 0 0
[junit4:junit4] 2> 353276 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[b!53 (1439095880284110848)]} 0 3
[junit4:junit4] 2> 353278 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[c!54 (1439095880289353728)]} 0 0
[junit4:junit4] 2> 353283 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!54 (1439095880292499456)]} 0 0
[junit4:junit4] 2> 353284 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[c!54 (1439095880292499456)]} 0 3
[junit4:junit4] 2> 353286 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[d!55 (1439095880297742336)]} 0 0
[junit4:junit4] 2> 353291 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!55 (1439095880300888064)]} 0 0
[junit4:junit4] 2> 353292 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[d!55 (1439095880300888064)]} 0 3
[junit4:junit4] 2> 353295 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[e!56 (1439095880306130944)]} 0 1
[junit4:junit4] 2> 353301 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!56 (1439095880311373824)]} 0 0
[junit4:junit4] 2> 353302 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!56 (1439095880311373824)]} 0 3
[junit4:junit4] 2> 353303 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[e!56]} 0 6
[junit4:junit4] 2> 353306 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[f!57 (1439095880317665280)]} 0 1
[junit4:junit4] 2> 353310 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!57 (1439095880320811008)]} 0 0
[junit4:junit4] 2> 353311 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[f!57 (1439095880320811008)]} 0 3
[junit4:junit4] 2> 353314 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[g!58 (1439095880326053888)]} 0 1
[junit4:junit4] 2> 353320 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!58 (1439095880331296768)]} 0 0
[junit4:junit4] 2> 353320 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!58 (1439095880331296768)]} 0 2
[junit4:junit4] 2> 353321 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[g!58]} 0 5
[junit4:junit4] 2> 353323 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[h!59 (1439095880336539648)]} 0 0
[junit4:junit4] 2> 353328 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!59 (1439095880339685376)]} 0 0
[junit4:junit4] 2> 353329 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[h!59 (1439095880339685376)]} 0 3
[junit4:junit4] 2> 353331 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[i!60 (1439095880344928256)]} 0 0
[junit4:junit4] 2> 353336 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!60 (1439095880348073984)]} 0 0
[junit4:junit4] 2> 353337 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[i!60 (1439095880348073984)]} 0 3
[junit4:junit4] 2> 353339 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[j!61 (1439095880353316864)]} 0 0
[junit4:junit4] 2> 353343 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!61 (1439095880355414016)]} 0 0
[junit4:junit4] 2> 353344 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[j!61 (1439095880355414016)]} 0 3
[junit4:junit4] 2> 353347 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[k!62 (1439095880361705472)]} 0 1
[junit4:junit4] 2> 353352 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!62 (1439095880363802624)]} 0 1
[junit4:junit4] 2> 353352 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[k!62 (1439095880363802624)]} 0 3
[junit4:junit4] 2> 353355 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[l!63 (1439095880369045504)]} 0 1
[junit4:junit4] 2> 353359 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!63 (1439095880372191232)]} 0 0
[junit4:junit4] 2> 353360 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[l!63 (1439095880372191232)]} 0 3
[junit4:junit4] 2> 353363 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[m!64 (1439095880378482688)]} 0 1
[junit4:junit4] 2> 353369 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!64 (1439095880382676992)]} 0 0
[junit4:junit4] 2> 353370 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[m!64 (1439095880382676992)]} 0 3
[junit4:junit4] 2> 353371 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[m!64]} 0 6
[junit4:junit4] 2> 353374 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[n!65 (1439095880388968448)]} 0 1
[junit4:junit4] 2> 353380 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!65 (1439095880394211328)]} 0 0
[junit4:junit4] 2> 353381 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[n!65 (1439095880394211328)]} 0 3
[junit4:junit4] 2> 353382 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[n!65]} 0 6
[junit4:junit4] 2> 353384 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[o!66 (1439095880400502784)]} 0 0
[junit4:junit4] 2> 353391 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!66 (1439095880405745664)]} 0 0
[junit4:junit4] 2> 353392 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[o!66 (1439095880405745664)]} 0 3
[junit4:junit4] 2> 353392 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[o!66]} 0 5
[junit4:junit4] 2> 353395 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[p!67 (1439095880412037120)]} 0 0
[junit4:junit4] 2> 353402 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!67 (1439095880417280000)]} 0 1
[junit4:junit4] 2> 353403 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[p!67 (1439095880417280000)]} 0 4
[junit4:junit4] 2> 353403 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[p!67]} 0 5
[junit4:junit4] 2> 353406 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[q!68 (1439095880423571456)]} 0 1
[junit4:junit4] 2> 353413 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!68 (1439095880427765760)]} 0 1
[junit4:junit4] 2> 353413 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[q!68 (1439095880427765760)]} 0 3
[junit4:junit4] 2> 353414 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[q!68]} 0 6
[junit4:junit4] 2> 353417 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[r!69 (1439095880434057216)]} 0 1
[junit4:junit4] 2> 353422 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!69 (1439095880437202944)]} 0 1
[junit4:junit4] 2> 353423 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[r!69 (1439095880437202944)]} 0 4
[junit4:junit4] 2> 353425 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[s!70 (1439095880443494400)]} 0 0
[junit4:junit4] 2> 353430 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!70 (1439095880446640128)]} 0 0
[junit4:junit4] 2> 353431 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[s!70 (1439095880446640128)]} 0 3
[junit4:junit4] 2> 353434 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[t!71 (1439095880451883008)]} 0 1
[junit4:junit4] 2> 353438 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!71 (1439095880455028736)]} 0 0
[junit4:junit4] 2> 353439 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[t!71 (1439095880455028736)]} 0 3
[junit4:junit4] 2> 353441 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[u!72 (1439095880460271616)]} 0 0
[junit4:junit4] 2> 353448 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!72 (1439095880465514496)]} 0 1
[junit4:junit4] 2> 353449 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[u!72 (1439095880465514496)]} 0 4
[junit4:junit4] 2> 353449 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[u!72]} 0 5
[junit4:junit4] 2> 353452 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[v!73 (1439095880471805952)]} 0 1
[junit4:junit4] 2> 353459 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!73 (1439095880476000256)]} 0 1
[junit4:junit4] 2> 353459 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[v!73 (1439095880476000256)]} 0 3
[junit4:junit4] 2> 353460 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[v!73]} 0 6
[junit4:junit4] 2> 353463 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[w!74 (1439095880482291712)]} 0 1
[junit4:junit4] 2> 353468 T2822 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!74 (1439095880485437440)]} 0 1
[junit4:junit4] 2> 353468 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[w!74 (1439095880485437440)]} 0 3
[junit4:junit4] 2> 353471 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[x!75 (1439095880491728896)]} 0 0
[junit4:junit4] 2> 353476 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!75 (1439095880494874624)]} 0 0
[junit4:junit4] 2> 353477 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[x!75 (1439095880494874624)]} 0 3
[junit4:junit4] 2> 353479 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[y!76 (1439095880500117504)]} 0 0
[junit4:junit4] 2> 353484 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!76 (1439095880503263232)]} 0 0
[junit4:junit4] 2> 353485 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[y!76 (1439095880503263232)]} 0 3
[junit4:junit4] 2> 353487 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[z!77 (1439095880508506112)]} 0 0
[junit4:junit4] 2> 353494 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!77 (1439095880513748992)]} 0 1
[junit4:junit4] 2> 353495 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[z!77 (1439095880513748992)]} 0 4
[junit4:junit4] 2> 353495 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[z!77]} 0 5
[junit4:junit4] 2> 353498 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[a!78 (1439095880520040448)]} 0 0
[junit4:junit4] 2> 353506 T2842 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!78 (1439095880525283328)]} 0 0
[junit4:junit4] 2> 353507 T2806 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!78 (1439095880525283328)]} 0 4
[junit4:junit4] 2> 353508 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[a!78]} 0 7
[junit4:junit4] 2> 353511 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[b!79 (1439095880532623360)]} 0 1
[junit4:junit4] 2> 353516 T2823 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!79 (1439095880535769088)]} 0 0
[junit4:junit4] 2> 353517 T2790 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[b!79 (1439095880535769088)]} 0 4
[junit4:junit4] 2> 353520 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[c!80 (1439095880543109120)]} 0 0
[junit4:junit4] 2> 353526 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!80 (1439095880546254848)]} 0 1
[junit4:junit4] 2> 353526 T2793 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[c!80 (1439095880546254848)]} 0 3
[junit4:junit4] 2> 353529 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[d!81 (1439095880552546304)]} 0 0
[junit4:junit4] 2> 353534 T2841 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!81 (1439095880555692032)]} 0 1
[junit4:junit4] 2> 353535 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[d!81 (1439095880555692032)]} 0 4
[junit4:junit4] 2> 353537 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[e!82 (1439095880560934912)]} 0 0
[junit4:junit4] 2> 353543 T2839 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!82 (1439095880564080640)]} 0 1
[junit4:junit4] 2> 353543 T2809 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[e!82 (1439095880564080640)]} 0 3
[junit4:junit4] 2> 353546 T2771 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[f!83 (1439095880570372096)]} 0 0
[junit4:junit4] 2> 353551 T2840 C785 P42486 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!83 (1439095880573517824)]} 0 0
[junit4:junit4] 2> 353552 T2807 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[f!83 (1439095880573517824)]} 0 3
[junit4:junit4] 2> 353554 T2772 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[g!84 (1439095880578760704)]} 0 0
[junit4:junit4] 2> 353559 T2825 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!84 (1439095880580857856)]} 0 1
[junit4:junit4] 2> 353559 T2791 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[g!84 (1439095880580857856)]} 0 3
[junit4:junit4] 2> 353562 T2773 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[h!85 (1439095880586100736)]} 0 1
[junit4:junit4] 2> 353568 T2824 C786 P40659 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:55944/wcv/n/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!85 (1439095880591343616)]} 0 0
[junit4:junit4] 2> 353569 T2792 C784 P55944 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={distrib.from=http://127.0.0.1:49506/wcv/n/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[h!85 (1439095880591343616)]} 0 3
[junit4:junit4] 2> 353570 T2808 C783 P49506 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[h!85]} 0 6
[junit4:junit4] 2> 353572 T2770 C782 P40525 oasup.LogUpdateProcessor.finish [collection1] webapp=/wcv/n path=/update params={wt=javabin&version=2} {add=[i!86 (1439095880597635072)]} 0 0
[junit4:junit4] 2> 353579 T2822 C786 P40659 oasup.LogUpdateProcessor.fi
[...truncated too long message...]
llection/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:40525_wcv%2Fn",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:40525/wcv/n"}
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89943491087433740-127.0.0.1:42486_wcv%2Fn-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89943491087433738-127.0.0.1:40659_wcv%2Fn-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89943491087433736-127.0.0.1:49506_wcv%2Fn-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89943491087433734-127.0.0.1:55944_wcv%2Fn-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89943491087433731-127.0.0.1:40525_wcv%2Fn-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89943491087433731-127.0.0.1:40525_wcv%2Fn-n_0000000000"}
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 1> -
[junit4:junit4] 1> rstate:active live:true
[junit4:junit4] 1> rstate:active live:true
[junit4:junit4] 1> rstate:active live:true
[junit4:junit4] 1> rstate:active live:true
[junit4:junit4] 1> rstate:active live:true
[junit4:junit4] 1> rstate:active live:true
[junit4:junit4] 1> rstate:active live:true
[junit4:junit4] 1> rstate:active live:true
[junit4:junit4] 1> no one is recoverying
[junit4:junit4] 2> 484709 T2755 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 153321 T2754 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4] 2> 173354 T2754 ccr.ThreadLeakControl.checkThreadLeaks SEVERE 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
[junit4:junit4] 2> 1) Thread[id=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs]
[junit4:junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4:junit4] 2> at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4:junit4] 2> at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
[junit4:junit4] 2> at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:360)
[junit4:junit4] 2> at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:939)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] 2> 173354 T2754 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4:junit4] 2> 1) Thread[id=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs]
[junit4:junit4] 2> 176356 T2754 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4:junit4] 2> 1) Thread[id=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs]
[junit4:junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4:junit4] 2> at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4:junit4] 2> at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
[junit4:junit4] 2> at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:360)
[junit4:junit4] 2> at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:939)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=is_IS, timezone=America/Argentina/Salta
[junit4:junit4] 2> NOTE: Linux 3.2.0-48-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=1,free=153235896,total=423866368
[junit4:junit4] 2> NOTE: All tests run in this JVM: [HdfsUnloadDistributedZkTest, BasicDistributedZk2Test, TestSchemaSimilarityResource, TestElisionMultitermQuery, TestSystemIdResolver, TestStressLucene, LeaderElectionIntegrationTest, HdfsCollectionsAPIDistributedZkTest, TestMergePolicyConfig, TestLMJelinekMercerSimilarityFactory, DateMathParserTest, TestRecoveryHdfs, TestManagedSchema, TestUniqueKeyFieldResource, TestQueryTypes, URLClassifyProcessorTest, OpenExchangeRatesOrgProviderTest, HdfsRecoveryZkTest, TestBM25SimilarityFactory, TestSolr4Spatial, SolrRequestParserTest, TestCloudManagedSchemaAddField, TestWordDelimiterFilterFactory, SpellPossibilityIteratorTest, HdfsSyncSliceTest, TestRandomFaceting, OutputWriterTest, DistanceFunctionTest, TestZkChroot, TestUpdate, JSONWriterTest, TestIndexSearcher, TestStressReorder, SpellCheckCollatorTest, SuggesterWFSTTest, TestReloadAndDeleteDocs, CollectionsAPIDistributedZkTest, ShardSplitTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardSplitTest -Dtests.seed=575283B251B3D6A -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=is_IS -Dtests.timezone=America/Argentina/Salta -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 0.00s J1 | ShardSplitTest (suite) <<<
[junit4:junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
[junit4:junit4] > 1) Thread[id=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs]
[junit4:junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4:junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4:junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
[junit4:junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:360)
[junit4:junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:939)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([575283B251B3D6A]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4:junit4] > 1) Thread[id=2903, name=IPC Parameter Sending Thread #2, state=TIMED_WAITING, group=TGRP-TestRecoveryHdfs]
[junit4:junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4:junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4:junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
[junit4:junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:360)
[junit4:junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:939)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([575283B251B3D6A]:0)
[junit4:junit4] Completed on J1 in 176.39s, 1 test, 2 errors <<< FAILURES!
[...truncated 586 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:386: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:366: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:190: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:443: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1245: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:889: There were test failures: 312 suites, 1316 tests, 2 suite-level errors, 655 ignored (3 assumptions)
Total time: 28 minutes 31 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b94 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure