lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@sd-datasolutions.de>
Subject [JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.6.0_37) - Build # 2198 - Failure!
Date Mon, 17 Dec 2012 14:03:02 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-4.x-Windows/2198/
Java: 64bit/jdk1.6.0_37 -XX:+UseSerialGC

1 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.RecoveryZkTest

Error Message:
Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=3047, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.

Stack Trace:
com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=3047, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
	at __randomizedtesting.SeedInfo.seed([E9DD10EF2468392C]:0)
	at java.lang.Thread.getStackTrace(Thread.java:1479)
	at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
	at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:517)
	at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:983)
	at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:875)
	at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:867)
	at org.apache.solr.core.MockDirectoryFactory.create(MockDirectoryFactory.java:33)
	at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:256)
	at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:212)
	at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:376)
	at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:273)
	at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:153)
	at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:408)
	at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:223)
Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\index1587515882tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@5610e743)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.lucene.util.CloseableDirectory.close(CloseableDirectory.java:47)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:602)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:599)
	at com.carrotsearch.randomizedtesting.RandomizedContext.closeResources(RandomizedContext.java:167)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$2.afterAlways(RandomizedRunner.java:615)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:662)




Build Log:
[...truncated 8248 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4]   2> 1 T2988 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 4 T2988 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-RecoveryZkTest-1355752361430
[junit4:junit4]   2> 6 T2988 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 8 T2989 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 11 T2989 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 11 T2989 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 11 T2989 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 12 T2989 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 13 T2989 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\zookeeper\server1\data\version-2\snapshot.0
[junit4:junit4]   2> 107 T2988 oasc.ZkTestServer.run start zk server on port:50407
[junit4:junit4]   2> 107 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@6e1f6243
[junit4:junit4]   2> 109 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 109 T2994 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 110 T2994 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 110 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50410
[junit4:junit4]   2> 110 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50410
[junit4:junit4]   2> 112 T2992 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 124 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0000 with negotiated timeout 10000 for client /127.0.0.1:50410
[junit4:junit4]   2> 124 T2994 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0000, negotiated timeout = 10000
[junit4:junit4]   2> 125 T2995 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e1f6243 name:ZooKeeperConnection Watcher:127.0.0.1:50407 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 125 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 125 T2988 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 130 T2993 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13ba9234dde0000
[junit4:junit4]   2> 133 T2990 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50410 which had sessionid 0x13ba9234dde0000
[junit4:junit4]   2> 132 T2988 oaz.ZooKeeper.close Session: 0x13ba9234dde0000 closed
[junit4:junit4]   2> 133 T2995 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 133 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@77536045
[junit4:junit4]   2> 134 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 135 T2996 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 135 T2996 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 136 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50413
[junit4:junit4]   2> 136 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50413
[junit4:junit4]   2> 138 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0001 with negotiated timeout 10000 for client /127.0.0.1:50413
[junit4:junit4]   2> 138 T2996 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0001, negotiated timeout = 10000
[junit4:junit4]   2> 138 T2997 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77536045 name:ZooKeeperConnection Watcher:127.0.0.1:50407/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 138 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 138 T2988 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 144 T2988 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 148 T2988 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 152 T2988 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 156 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 157 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 165 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 166 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 171 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 171 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 179 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 180 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 185 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 185 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 189 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 189 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 193 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 194 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 198 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 198 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 202 T2988 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 203 T2988 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 207 T2993 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13ba9234dde0001
[junit4:junit4]   2> 209 T2990 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50413 which had sessionid 0x13ba9234dde0001
[junit4:junit4]   2> 209 T2988 oaz.ZooKeeper.close Session: 0x13ba9234dde0001 closed
[junit4:junit4]   2> 209 T2997 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 517 T2988 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 520 T2988 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50414
[junit4:junit4]   2> 521 T2988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 522 T2988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633
[junit4:junit4]   2> 522 T2988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633\'
[junit4:junit4]   2> 557 T2988 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 558 T2988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 558 T2988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633
[junit4:junit4]   2> 558 T2988 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633\solr.xml
[junit4:junit4]   2> 559 T2988 oasc.CoreContainer.<init> New CoreContainer 577027349
[junit4:junit4]   2> 559 T2988 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633\'
[junit4:junit4]   2> 560 T2988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633\'
[junit4:junit4]   2> 580 T2988 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4]   2> 581 T2988 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 581 T2988 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 581 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 581 T2988 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 583 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 583 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 583 T2988 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 584 T2988 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 584 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4]   2> 597 T2988 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 619 T2988 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50407/solr
[junit4:junit4]   2> 620 T2988 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 620 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@17c0eaaa
[junit4:junit4]   2> 622 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 623 T3007 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 624 T3007 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 624 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50419
[junit4:junit4]   2> 624 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50419
[junit4:junit4]   2> 634 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0002 with negotiated timeout 20000 for client /127.0.0.1:50419
[junit4:junit4]   2> 634 T3007 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0002, negotiated timeout = 20000
[junit4:junit4]   2> 635 T3008 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17c0eaaa name:ZooKeeperConnection Watcher:127.0.0.1:50407 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 635 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 637 T2993 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13ba9234dde0002
[junit4:junit4]   2> 639 T2988 oaz.ZooKeeper.close Session: 0x13ba9234dde0002 closed
[junit4:junit4]   2> 639 T2990 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50419 which had sessionid 0x13ba9234dde0002
[junit4:junit4]   2> 640 T3008 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 639 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4]   2> 643 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@e135f2b
[junit4:junit4]   2> 645 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 646 T3009 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 646 T3009 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 647 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50422
[junit4:junit4]   2> 647 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50422
[junit4:junit4]   2> 649 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0003 with negotiated timeout 20000 for client /127.0.0.1:50422
[junit4:junit4]   2> 649 T3009 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0003, negotiated timeout = 20000
[junit4:junit4]   2> 649 T3010 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e135f2b name:ZooKeeperConnection Watcher:127.0.0.1:50407/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 649 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 651 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 653 T2988 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 655 T2988 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50414_
[junit4:junit4]   2> 656 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:delete cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50414_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50414_
[junit4:junit4]   2> 657 T2988 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50414_
[junit4:junit4]   2> 661 T2988 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 669 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:delete cxid:0x15 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 670 T2988 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 673 T2988 oasc.Overseer.start Overseer (id=88850586759200771-127.0.0.1:50414_-n_0000000000) starting
[junit4:junit4]   2> 674 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 676 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 677 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 679 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 680 T3012 oasc.OverseerCollectionProcessor.run Process current queue of collection messages
[junit4:junit4]   2> 681 T2988 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 683 T2988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 686 T3011 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 691 T3013 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633\collection1
[junit4:junit4]   2> 691 T3013 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 693 T3013 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 693 T3013 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 696 T3013 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633\collection1\'
[junit4:junit4]   2> 696 T3013 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 697 T3013 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633/collection1/lib/README' to classloader
[junit4:junit4]   2> 749 T3013 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 836 T3013 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 838 T3013 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 843 T3013 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1477 T3013 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1487 T3013 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1492 T3013 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1508 T3013 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1512 T3013 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1516 T3013 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1518 T3013 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1520 T3013 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1355752361633\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1355752361428/control/data\
[junit4:junit4]   2> 1520 T3013 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a22ce00
[junit4:junit4]   2> 1520 T3013 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1524 T3013 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\control\data forceNew:false
[junit4:junit4]   2> 1526 T3013 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\control\data
[junit4:junit4]   2> 1526 T3013 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1355752361428/control/data\index/
[junit4:junit4]   2> 1527 T3013 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\control\data\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1527 T3013 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\control\data\index forceNew:false
[junit4:junit4]   2> 1529 T3013 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@421639d1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d6d2a92)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1529 T3013 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1531 T3013 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\control\data\index
[junit4:junit4]   2> 1531 T3013 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1533 T3013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1533 T3013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1533 T3013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1533 T3013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1534 T3013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1534 T3013 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1534 T3013 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1535 T3013 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1535 T3013 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1536 T3013 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1536 T3013 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1537 T3013 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1538 T3013 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1538 T3013 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1538 T3013 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1539 T3013 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1539 T3013 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1540 T3013 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1540 T3013 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1541 T3013 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1542 T3013 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1542 T3013 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1543 T3013 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1544 T3013 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1544 T3013 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1545 T3013 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1552 T3013 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1556 T3013 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1558 T3013 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 1560 T3013 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\control\data
[junit4:junit4]   2> 1560 T3013 oass.SolrIndexSearcher.<init> Opening Searcher@71f712 main
[junit4:junit4]   2> 1562 T3013 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1562 T3013 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1562 T3013 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1584 T3013 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1656 T3014 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@71f712 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1658 T3013 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1658 T3013 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1660 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x53 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1685 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1687 T3011 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50414_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50414"}
[junit4:junit4]   2> 1687 T3011 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 1688 T3011 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 1689 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x5b zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1711 T3010 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> 2161 T3013 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2161 T3013 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:50414 shardId:shard1
[junit4:junit4]   2> 2163 T3013 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2185 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:delete cxid:0x75 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2188 T3013 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2189 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x76 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2195 T3013 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2196 T3013 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2196 T3013 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50414/collection1/
[junit4:junit4]   2> 2196 T3013 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2197 T3013 oasc.SyncStrategy.syncToMe http://127.0.0.1:50414/collection1/ has no replicas
[junit4:junit4]   2> 2197 T3013 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50414/collection1/
[junit4:junit4]   2> 2198 T3013 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2211 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0003 type:create cxid:0x80 zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2221 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2245 T3010 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> 2269 T3013 oasc.ZkController.register We are http://127.0.0.1:50414/collection1/ and leader is http://127.0.0.1:50414/collection1/
[junit4:junit4]   2> 2269 T3013 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50414
[junit4:junit4]   2> 2269 T3013 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2271 T3013 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 2271 T3013 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2276 T3013 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2278 T2988 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 2279 T2988 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2279 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2295 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 2301 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@6e8f590b
[junit4:junit4]   2> 2304 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2304 T3015 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 2305 T3015 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 2305 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50425
[junit4:junit4]   2> 2306 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50425
[junit4:junit4]   2> 2307 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0004 with negotiated timeout 10000 for client /127.0.0.1:50425
[junit4:junit4]   2> 2307 T3015 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0004, negotiated timeout = 10000
[junit4:junit4]   2> 2307 T3016 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e8f590b name:ZooKeeperConnection Watcher:127.0.0.1:50407/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2308 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2309 T2988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2310 T2988 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 2626 T2988 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 2628 T2988 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50426
[junit4:junit4]   2> 2630 T2988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2630 T2988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735
[junit4:junit4]   2> 2630 T2988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735\'
[junit4:junit4]   2> 2661 T2988 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2662 T2988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2662 T2988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735
[junit4:junit4]   2> 2663 T2988 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735\solr.xml
[junit4:junit4]   2> 2663 T2988 oasc.CoreContainer.<init> New CoreContainer 2090671326
[junit4:junit4]   2> 2664 T2988 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735\'
[junit4:junit4]   2> 2664 T2988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735\'
[junit4:junit4]   2> 2684 T2988 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4]   2> 2684 T2988 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2684 T2988 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 2685 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2685 T2988 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2685 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2685 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2687 T2988 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2687 T2988 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2687 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4]   2> 2699 T2988 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2721 T2988 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50407/solr
[junit4:junit4]   2> 2721 T2988 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 2721 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7a6aaca7
[junit4:junit4]   2> 2722 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2723 T3026 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 2724 T3026 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 2724 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50431
[junit4:junit4]   2> 2725 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50431
[junit4:junit4]   2> 2741 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0005 with negotiated timeout 20000 for client /127.0.0.1:50431
[junit4:junit4]   2> 2741 T3026 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0005, negotiated timeout = 20000
[junit4:junit4]   2> 2741 T3027 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a6aaca7 name:ZooKeeperConnection Watcher:127.0.0.1:50407 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2742 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2743 T2993 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13ba9234dde0005
[junit4:junit4]   2> 2745 T2988 oaz.ZooKeeper.close Session: 0x13ba9234dde0005 closed
[junit4:junit4]   2> 2745 T2990 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ba9234dde0005, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2> 
[junit4:junit4]   2> 2745 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4]   2> 2747 T3027 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 2747 T2990 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50431 which had sessionid 0x13ba9234dde0005
[junit4:junit4]   2> 2750 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2b309389
[junit4:junit4]   2> 2752 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2754 T3028 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 2755 T3028 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 2755 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50434
[junit4:junit4]   2> 2756 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50434
[junit4:junit4]   2> 2756 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2758 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0006 with negotiated timeout 20000 for client /127.0.0.1:50434
[junit4:junit4]   2> 2758 T3028 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0006, negotiated timeout = 20000
[junit4:junit4]   2> 2758 T3029 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b309389 name:ZooKeeperConnection Watcher:127.0.0.1:50407/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2759 T3011 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50414_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50414"}
[junit4:junit4]   2> 2759 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2760 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0006 type:create cxid:0x1 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2763 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0006 type:create cxid:0x2 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2767 T2988 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50426_
[junit4:junit4]   2> 2768 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0006 type:delete cxid:0x4 zxid:0x4e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50426_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50426_
[junit4:junit4]   2> 2770 T3010 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> 2770 T3016 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> 2771 T2988 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50426_
[junit4:junit4]   2> 2777 T3016 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 2780 T3010 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 2780 T3016 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 2783 T3010 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 2785 T2988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2794 T3030 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735\collection1
[junit4:junit4]   2> 2794 T3030 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 2795 T3030 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2795 T3030 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 2797 T3030 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735\collection1\'
[junit4:junit4]   2> 2798 T3030 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 2800 T3030 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735/collection1/lib/README' to classloader
[junit4:junit4]   2> 2851 T3030 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 2955 T3030 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2957 T3030 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 2962 T3030 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 3600 T3030 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 3609 T3030 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 3613 T3030 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 3627 T3030 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3632 T3030 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3636 T3030 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3638 T3030 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3639 T3030 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1355752363735\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1355752361428/jetty1\
[junit4:junit4]   2> 3639 T3030 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a22ce00
[junit4:junit4]   2> 3639 T3030 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 3644 T3030 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty1 forceNew:false
[junit4:junit4]   2> 3644 T3030 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty1
[junit4:junit4]   2> 3644 T3030 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1355752361428/jetty1\index/
[junit4:junit4]   2> 3646 T3030 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 3646 T3030 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty1\index forceNew:false
[junit4:junit4]   2> 3650 T3030 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@67d329f3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6415b5da)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 3650 T3030 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 3650 T3030 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty1\index
[junit4:junit4]   2> 3651 T3030 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 3652 T3030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 3652 T3030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 3652 T3030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 3653 T3030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 3653 T3030 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 3653 T3030 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 3653 T3030 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 3654 T3030 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 3654 T3030 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 3654 T3030 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 3655 T3030 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 3656 T3030 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 3656 T3030 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 3656 T3030 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 3656 T3030 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 3658 T3030 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 3658 T3030 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3659 T3030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3660 T3030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3660 T3030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3661 T3030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3661 T3030 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3662 T3030 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3662 T3030 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3664 T3030 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 3664 T3030 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 3671 T3030 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 3675 T3030 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 3677 T3030 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 3680 T3030 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty1
[junit4:junit4]   2> 3681 T3030 oass.SolrIndexSearcher.<init> Opening Searcher@cc5ec1 main
[junit4:junit4]   2> 3682 T3030 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 3682 T3030 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 3683 T3030 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 3694 T3030 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 3763 T3031 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cc5ec1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 3766 T3030 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 3766 T3030 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3770 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3770 T3011 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50426_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50426"}
[junit4:junit4]   2> 3770 T3011 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 3771 T3011 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 3777 T3010 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> 3777 T3016 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> 3777 T3029 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> 4263 T3030 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 4263 T3030 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:50426 shardId:shard1
[junit4:junit4]   2> 4264 T3030 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 4274 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0006 type:delete cxid:0x43 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 4275 T3030 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 4276 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0006 type:create cxid:0x44 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4279 T3030 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 4279 T3030 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 4280 T3030 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50426/collection1/
[junit4:junit4]   2> 4280 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4280 T3030 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 4280 T3030 oasc.SyncStrategy.syncToMe http://127.0.0.1:50426/collection1/ has no replicas
[junit4:junit4]   2> 4280 T3030 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50426/collection1/
[junit4:junit4]   2> 4281 T3030 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 4290 T3029 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> 4291 T3010 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> 4292 T3016 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> 4298 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0006 type:create cxid:0x50 zxid:0x64 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4794 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4805 T3010 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> 4805 T3029 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> 4805 T3016 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> 4855 T3030 oasc.ZkController.register We are http://127.0.0.1:50426/collection1/ and leader is http://127.0.0.1:50426/collection1/
[junit4:junit4]   2> 4855 T3030 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50426
[junit4:junit4]   2> 4855 T3030 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4855 T3030 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 4855 T3030 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 4858 T3030 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4859 T2988 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 4859 T2988 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4860 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 5173 T2988 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 5176 T2988 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50435
[junit4:junit4]   2> 5179 T2988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5180 T2988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291
[junit4:junit4]   2> 5180 T2988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291\'
[junit4:junit4]   2> 5211 T2988 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 5211 T2988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5212 T2988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291
[junit4:junit4]   2> 5212 T2988 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291\solr.xml
[junit4:junit4]   2> 5213 T2988 oasc.CoreContainer.<init> New CoreContainer 1140731520
[junit4:junit4]   2> 5213 T2988 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291\'
[junit4:junit4]   2> 5214 T2988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291\'
[junit4:junit4]   2> 5233 T2988 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4]   2> 5234 T2988 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 5234 T2988 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 5235 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 5235 T2988 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 5235 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 5236 T2988 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 5236 T2988 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 5237 T2988 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 5237 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4]   2> 5249 T2988 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 5270 T2988 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50407/solr
[junit4:junit4]   2> 5270 T2988 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 5271 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@c45895
[junit4:junit4]   2> 5272 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 5273 T3041 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 5274 T3041 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 5274 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50440
[junit4:junit4]   2> 5274 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50440
[junit4:junit4]   2> 5284 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0007 with negotiated timeout 20000 for client /127.0.0.1:50440
[junit4:junit4]   2> 5284 T3041 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0007, negotiated timeout = 20000
[junit4:junit4]   2> 5284 T3042 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c45895 name:ZooKeeperConnection Watcher:127.0.0.1:50407 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5284 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 5286 T2993 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13ba9234dde0007
[junit4:junit4]   2> 5287 T2990 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50440 which had sessionid 0x13ba9234dde0007
[junit4:junit4]   2> 5288 T2988 oaz.ZooKeeper.close Session: 0x13ba9234dde0007 closed
[junit4:junit4]   2> 5288 T3042 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 5288 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4]   2> 5291 T2988 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50407/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@639aea8b
[junit4:junit4]   2> 5293 T2988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 5294 T3043 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50407. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 5295 T3043 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50407, initiating session
[junit4:junit4]   2> 5295 T2990 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50443
[junit4:junit4]   2> 5295 T2990 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50443
[junit4:junit4]   2> 5297 T2992 oazs.ZooKeeperServer.finishSessionInit Established session 0x13ba9234dde0008 with negotiated timeout 20000 for client /127.0.0.1:50443
[junit4:junit4]   2> 5297 T3043 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50407, sessionid = 0x13ba9234dde0008, negotiated timeout = 20000
[junit4:junit4]   2> 5298 T3044 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@639aea8b name:ZooKeeperConnection Watcher:127.0.0.1:50407/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5298 T2988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 5299 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0008 type:create cxid:0x1 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5300 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0008 type:create cxid:0x2 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5302 T2988 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50435_
[junit4:junit4]   2> 5303 T2993 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13ba9234dde0008 type:delete cxid:0x4 zxid:0x70 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50435_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50435_
[junit4:junit4]   2> 5305 T2988 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50435_
[junit4:junit4]   2> 5307 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5307 T3011 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50426_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50426"}
[junit4:junit4]   2> 5308 T3010 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> 5309 T3016 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> 5311 T3029 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 5311 T3029 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> 5313 T3016 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 5317 T3029 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> 5317 T3016 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> 5318 T2988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5323 T3010 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 5323 T3010 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> 5328 T3045 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291\collection1
[junit4:junit4]   2> 5328 T3045 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5329 T3045 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5329 T3045 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5331 T3045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291\collection1\'
[junit4:junit4]   2> 5333 T3045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5334 T3045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291/collection1/lib/README' to classloader
[junit4:junit4]   2> 5402 T3045 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 5472 T3045 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5474 T3045 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5479 T3045 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6123 T3045 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6132 T3045 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6136 T3045 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6153 T3045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6158 T3045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6163 T3045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6164 T3045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6166 T3045 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1355752366291\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1355752361428/jetty2\
[junit4:junit4]   2> 6166 T3045 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a22ce00
[junit4:junit4]   2> 6166 T3045 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 6171 T3045 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2 forceNew:false
[junit4:junit4]   2> 6171 T3045 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2
[junit4:junit4]   2> 6172 T3045 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1355752361428/jetty2\index/
[junit4:junit4]   2> 6172 T3045 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6173 T3045 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2\index forceNew:false
[junit4:junit4]   2> 6176 T3045 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@53790030 lockFactory=org.apache.lucene.store.NativeFSLockFactory@320ee1f2)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6176 T3045 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6177 T3045 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2\index
[junit4:junit4]   2> 6177 T3045 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 6179 T3045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6179 T3045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 6179 T3045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6180 T3045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 6181 T3045 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6181 T3045 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6181 T3045 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6182 T3045 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6183 T3045 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6183 T3045 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6184 T3045 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6184 T3045 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6186 T3045 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6186 T3045 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6186 T3045 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6187 T3045 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6187 T3045 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6187 T3045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6187 T3045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6189 T3045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6189 T3045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6190 T3045 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6190 T3045 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6191 T3045 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6192 T3045 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6193 T3045 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6200 T3045 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6205 T3045 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6207 T3045 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 6209 T3045 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2
[junit4:junit4]   2> 6209 T3045 oass.SolrIndexSearcher.<init> Opening Searcher@39934474 main
[junit4:junit4]   2> 6212 T3045 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6212 T3045 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6212 T3045 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6225 T3045 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6284 T3046 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@39934474 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6287 T3045 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 6287 T3045 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6316 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6317 T3011 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50435_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50435"}
[junit4:junit4]   2> 6317 T3011 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 6317 T3011 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6324 T3029 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> 6324 T3016 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> 6325 T3010 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> 6325 T3044 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> 6785 T3045 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 6785 T3045 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:50435 shardId:shard1
[junit4:junit4]   2> 6796 T3045 oasc.ZkController.register We are http://127.0.0.1:50435/collection1/ and leader is http://127.0.0.1:50426/collection1/
[junit4:junit4]   2> 6796 T3045 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50435
[junit4:junit4]   2> 6797 T3045 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 6797 T3045 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C265 name=collection1 org.apache.solr.core.SolrCore@546f29da url=http://127.0.0.1:50435/collection1 node=127.0.0.1:50435_
[junit4:junit4]   2> 6798 T3047 C265 P50435 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 6799 T3047 C265 P50435 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 6799 T3047 C265 P50435 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 6799 T3045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6799 T3047 C265 P50435 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6802 T2988 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 6804 T2988 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6804 T3047 C265 P50435 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50426/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 6805 T3047 C265 P50435 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:50435 START replicas=[http://127.0.0.1:50426/collection1/] nUpdates=100
[junit4:junit4]   2> 6805 T2988 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 6805 T3047 C265 P50435 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 6807 T3047 C265 P50435 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 6807 T3047 C265 P50435 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 6808 T3047 C265 P50435 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C266 name=collection1 org.apache.solr.core.SolrCore@6ee0b2af url=http://127.0.0.1:50426/collection1 node=127.0.0.1:50426_
[junit4:junit4]   2> 6820 T3025 C266 P50426 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 6820 T2988 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C267 name=collection1 org.apache.solr.core.SolrCore@20588e54 url=http://127.0.0.1:50414/collection1 node=127.0.0.1:50414_
[junit4:junit4]   2> 6834 T3002 C267 P50414 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\control\data
[junit4:junit4]   2> 6835 T3011 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6835 T3011 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50435_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50435"}
[junit4:junit4]   2> 6838 T3002 C267 P50414 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@421639d1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d6d2a92)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6839 T3002 C267 P50414 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6843 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10001 (1421609395296403457)]} 0 12
[junit4:junit4]   2> 6843 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[1 (1421609395296403456)]} 0 12
[junit4:junit4]   2> 6848 T3010 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> 6848 T3044 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> 6848 T3029 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> 6848 T3016 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> 6850 T3021 C266 P50426 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty1
[junit4:junit4]   2> 6855 T3021 C266 P50426 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@67d329f3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6415b5da)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6857 T3021 C266 P50426 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6858 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[1 (1421609395314229249)]} 0 9
[junit4:junit4]   2> 6858 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10001 (1421609395314229248)]} 0 9
[junit4:junit4]   2> 6863 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10002 (1421609395327860736)]} 0 1
[junit4:junit4]   2> 6863 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[2 (1421609395327860737)]} 0 1
[junit4:junit4]   2>  C265_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:50435_, base_url=http://127.0.0.1:50435}
[junit4:junit4]   2> 6877 T3037 C265 P50435 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2
[junit4:junit4]   2> 6881 T3037 C265 P50435 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@53790030 lockFactory=org.apache.lucene.store.NativeFSLockFactory@320ee1f2)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6882 T3037 C265 P50435 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6885 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 6885 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 6886 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[2 (1421609395333103616)]} 0 19
[junit4:junit4]   2> 6886 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10002 (1421609395332055040)]} 0 21
[junit4:junit4]   2> 6889 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10003 (1421609395355123712)]} 0 1
[junit4:junit4]   2> 6889 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[3 (1421609395355123713)]} 0 1
[junit4:junit4]   2> 6895 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6896 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10003 (1421609395358269440)]} 0 5
[junit4:junit4]   2> 6896 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6897 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[3 (1421609395359318016)]} 0 5
[junit4:junit4]   2> 6898 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10004 (1421609395365609472)]} 0 0
[junit4:junit4]   2> 6899 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[4 (1421609395366658048)]} 0 0
[junit4:junit4]   2> 6906 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6907 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10004 (1421609395369803776)]} 0 5
[junit4:junit4]   2> 6907 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 6908 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[4 (1421609395369803777)]} 0 6
[junit4:junit4]   2> 6910 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10002 (-1421609395378192384)]} 0 0
[junit4:junit4]   2> 6912 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[2 (-1421609395379240960)]} 0 1
[junit4:junit4]   2> 6917 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 6918 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6919 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[2 (-1421609395383435264)]} 0 4
[junit4:junit4]   2> 6919 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[10002 (-1421609395382386688)]} 0 5
[junit4:junit4]   2> 6924 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[5 (1421609395391823872)]} 0 1
[junit4:junit4]   2> 6925 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10005 (1421609395391823873)]} 0 2
[junit4:junit4]   2> 6930 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 6932 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[5 (1421609395394969600)]} 0 6
[junit4:junit4]   2> 6935 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6936 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10005 (1421609395399163904)]} 0 6
[junit4:junit4]   2> 6936 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[3 (-1421609395405455360)]} 0 0
[junit4:junit4]   2> 6939 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[10003 (-1421609395408601088)]} 0 0
[junit4:junit4]   2> 6942 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6943 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[3 (-1421609395408601088)]} 0 4
[junit4:junit4]   2> 6946 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 6947 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[10003 (-1421609395412795392)]} 0 4
[junit4:junit4]   2> 6950 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[6 (1421609395416989696)]} 0 3
[junit4:junit4]   2> 6954 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10006 (1421609395423281152)]} 0 2
[junit4:junit4]   2> 6960 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6961 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[6 (1421609395425378304)]} 0 7
[junit4:junit4]   2> 6966 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[7 (1421609395435864064)]} 0 2
[junit4:junit4]   2> 6966 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 6967 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10006 (1421609395429572608)]} 0 9
[junit4:junit4]   2> 6972 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10007 (1421609395441106944)]} 0 2
[junit4:junit4]   2> 6974 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 6975 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[7 (1421609395440058368)]} 0 6
[junit4:junit4]   2> 6979 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[8 (1421609395449495552)]} 0 1
[junit4:junit4]   2> 6981 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6982 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10007 (1421609395446349824)]} 0 7
[junit4:junit4]   2> 6987 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10008 (1421609395456835584)]} 0 2
[junit4:junit4]   2> 6989 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 6990 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[8 (1421609395454738432)]} 0 7
[junit4:junit4]   2> 6995 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[9 (1421609395465224192)]} 0 2
[junit4:junit4]   2> 6997 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 6999 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10008 (1421609395463127040)]} 0 8
[junit4:junit4]   2> 7002 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7003 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10009 (1421609395474661376)]} 0 1
[junit4:junit4]   2> 7004 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[9 (1421609395470467072)]} 0 6
[junit4:junit4]   2> 7009 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10 (1421609395480952832)]} 0 1
[junit4:junit4]   2> 7013 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7015 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10009 (1421609395480952832)]} 0 8
[junit4:junit4]   2> 7017 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7052 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10 (1421609395485147136)]} 0 40
[junit4:junit4]   2> 7053 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10010 (1421609395527090176)]} 0 2
[junit4:junit4]   2> 7054 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[11 (1421609395529187328)]} 0 0
[junit4:junit4]   2> 7059 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7060 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10010 (1421609395531284480)]} 0 4
[junit4:junit4]   2> 7061 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7062 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[11 (1421609395533381632)]} 0 4
[junit4:junit4]   2> 7062 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10011 (1421609395537575936)]} 0 0
[junit4:junit4]   2> 7064 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[12 (1421609395539673088)]} 0 0
[junit4:junit4]   2> 7072 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 7074 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10011 (1421609395540721664)]} 0 9
[junit4:junit4]   2> 7074 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 7074 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[12 (1421609395542818816)]} 0 7
[junit4:junit4]   2> 7077 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10012 (1421609395552256000)]} 0 1
[junit4:junit4]   2> 7077 T3001 C267 P50414 /update {wt=javabin&version=2} {delete=[12 (-1421609395553304576)]} 0 0
[junit4:junit4]   2> 7082 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7082 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7083 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[12 (-1421609395556450304)]} 0 3
[junit4:junit4]   2> 7084 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10012 (1421609395555401728)]} 0 5
[junit4:junit4]   2> 7086 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[10012 (-1421609395562741760)]} 0 0
[junit4:junit4]   2> 7087 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[13 (1421609395562741761)]} 0 1
[junit4:junit4]   2> 7090 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7091 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10012 (-1421609395565887488)]} 0 2
[junit4:junit4]   2> 7092 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7092 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[13 (1421609395565887489)]} 0 3
[junit4:junit4]   2> 7096 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10013 (1421609395571130368)]} 0 2
[junit4:junit4]   2> 7096 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[13 (-1421609395573227520)]} 0 0
[junit4:junit4]   2> 7101 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7102 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7104 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10013 (1421609395575324672)]} 0 6
[junit4:junit4]   2> 7105 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[13 (-1421609395576373248)]} 0 6
[junit4:junit4]   2> 7106 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10013 (-1421609395583713280)]} 0 0
[junit4:junit4]   2> 7110 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[14 (1421609395587907584)]} 0 0
[junit4:junit4]   2> 7112 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7114 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[10013 (-1421609395586859008)]} 0 5
[junit4:junit4]   2> 7117 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10014 (1421609395594199040)]} 0 1
[junit4:junit4]   2> 7118 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7119 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[14 (1421609395591053312)]} 0 6
[junit4:junit4]   2> 7123 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[15 (1421609395600490496)]} 0 1
[junit4:junit4]   2> 7125 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7125 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10014 (1421609395597344768)]} 0 6
[junit4:junit4]   2> 7131 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10015 (1421609395606781952)]} 0 3
[junit4:junit4]   2> 7133 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7137 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[15 (1421609395605733376)]} 0 10
[junit4:junit4]   2> 7141 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7142 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10015 (1421609395614121984)]} 0 8
[junit4:junit4]   2> 7143 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[16 (1421609395622510592)]} 0 0
[junit4:junit4]   2> 7145 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10016 (1421609395624607744)]} 0 0
[junit4:junit4]   2> 7151 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7155 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[16 (1421609395627753472)]} 0 7
[junit4:junit4]   2> 7171 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=18 
[junit4:junit4]   2> 7172 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10016 (1421609395627753473)]} 0 24
[junit4:junit4]   2> 7173 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[17 (1421609395653967872)]} 0 1
[junit4:junit4]   2> 7177 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10017 (1421609395657113600)]} 0 1
[junit4:junit4]   2> 7181 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7182 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[17 (1421609395659210752)]} 0 5
[junit4:junit4]   2> 7183 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7184 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[18 (1421609395665502208)]} 0 0
[junit4:junit4]   2> 7186 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10017 (1421609395660259328)]} 0 7
[junit4:junit4]   2> 7189 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10018 (1421609395670745088)]} 0 0
[junit4:junit4]   2> 7192 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7194 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[18 (1421609395669696512)]} 0 6
[junit4:junit4]   2> 7196 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7197 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10018 (1421609395674939392)]} 0 4
[junit4:junit4]   2> 7198 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[18 (-1421609395680182272)]} 0 0
[junit4:junit4]   2> 7199 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10018 (-1421609395681230848)]} 0 0
[junit4:junit4]   2> 7207 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7208 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7210 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[18 (-1421609395687522304)]} 0 5
[junit4:junit4]   2> 7211 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10018 (-1421609395688570880)]} 0 5
[junit4:junit4]   2> 7214 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10019 (1421609395695910912)]} 0 1
[junit4:junit4]   2> 7215 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[19 (1421609395698008064)]} 0 1
[junit4:junit4]   2> 7220 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7222 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7223 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10019 (1421609395702202368)]} 0 4
[junit4:junit4]   2> 7224 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[19 (1421609395701153792)]} 0 7
[junit4:junit4]   2> 7226 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10020 (1421609395709542400)]} 0 0
[junit4:junit4]   2> 7230 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[20 (1421609395711639552)]} 0 2
[junit4:junit4]   2> 7243 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7243 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7244 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[20 (1421609395716882432)]} 0 11
[junit4:junit4]   2> 7244 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10020 (1421609395715833856)]} 0 12
[junit4:junit4]   2> 7246 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[21 (1421609395730513920)]} 0 0
[junit4:junit4]   2> 7249 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10021 (1421609395733659648)]} 0 0
[junit4:junit4]   2> 7254 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7254 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[21 (1421609395734708224)]} 0 4
[junit4:junit4]   2> 7256 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7257 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10021 (1421609395736805376)]} 0 5
[junit4:junit4]   2> 7258 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[21 (-1421609395742048256)]} 0 1
[junit4:junit4]   2> 7259 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[10021 (-1421609395744145408)]} 0 0
[junit4:junit4]   2> 7262 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7263 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[21 (-1421609395745193984)]} 0 3
[junit4:junit4]   2> 7264 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7265 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[10021 (-1421609395747291136)]} 0 3
[junit4:junit4]   2> 7265 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[22 (1421609395750436864)]} 0 0
[junit4:junit4]   2> 7266 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[10022 (1421609395751485440)]} 0 0
[junit4:junit4]   2> 7273 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7273 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7274 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[22 (1421609395753582592)]} 0 6
[junit4:junit4]   2> 7274 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10022 (1421609395755679744)]} 0 4
[junit4:junit4]   2> 7278 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10023 (1421609395763019777)]} 0 1
[junit4:junit4]   2> 7278 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[23 (1421609395763019776)]} 0 1
[junit4:junit4]   2> 7283 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7284 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10023 (1421609395766165504)]} 0 4
[junit4:junit4]   2> 7286 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7286 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[23 (1421609395767214080)]} 0 5
[junit4:junit4]   2> 7287 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[10023 (-1421609395773505536)]} 0 0
[junit4:junit4]   2> 7289 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[23 (-1421609395775602688)]} 0 0
[junit4:junit4]   2> 7292 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7293 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[10023 (-1421609395776651264)]} 0 3
[junit4:junit4]   2> 7294 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7294 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[23 (-1421609395778748416)]} 0 2
[junit4:junit4]   2> 7295 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10024 (1421609395780845568)]} 0 1
[junit4:junit4]   2> 7297 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[24 (1421609395783991296)]} 0 0
[junit4:junit4]   2> 7302 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7303 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10024 (1421609395785039872)]} 0 5
[junit4:junit4]   2> 7304 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7305 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[24 (1421609395787137024)]} 0 5
[junit4:junit4]   2> 7306 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10025 (1421609395793428480)]} 0 0
[junit4:junit4]   2> 7312 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[25 (1421609395794477056)]} 0 5
[junit4:junit4]   2> 7315 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7316 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10025 (1421609395796574208)]} 0 7
[junit4:junit4]   2> 7322 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10026 (1421609395809157120)]} 0 1
[junit4:junit4]   2> 7323 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7324 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[25 (1421609395806011392)]} 0 6
[junit4:junit4]   2> 7328 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7329 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[26 (1421609395816497152)]} 0 1
[junit4:junit4]   2> 7329 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10026 (1421609395813351424)]} 0 5
[junit4:junit4]   2> 7332 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10027 (1421609395820691456)]} 0 0
[junit4:junit4]   2> 7337 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7339 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[26 (1421609395819642880)]} 0 8
[junit4:junit4]   2> 7342 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[27 (1421609395830128640)]} 0 1
[junit4:junit4]   2> 7344 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7346 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10027 (1421609395823837184)]} 0 11
[junit4:junit4]   2> 7348 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7349 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[27 (1421609395834322944)]} 0 4
[junit4:junit4]   2> 7350 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10028 (1421609395839565824)]} 0 0
[junit4:junit4]   2> 7352 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[28 (1421609395841662976)]} 0 0
[junit4:junit4]   2> 7357 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7358 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10028 (1421609395842711552)]} 0 5
[junit4:junit4]   2> 7360 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7360 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[28 (1421609395844808704)]} 0 6
[junit4:junit4]   2> 7363 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[10025 (-1421609395853197312)]} 0 0
[junit4:junit4]   2> 7364 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[25 (-1421609395854245888)]} 0 0
[junit4:junit4]   2> 7369 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7369 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10025 (-1421609395855294464)]} 0 4
[junit4:junit4]   2> 7371 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7371 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[25 (-1421609395858440192)]} 0 3
[junit4:junit4]   2> 7372 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10029 (1421609395862634496)]} 0 0
[junit4:junit4]   2> 7378 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[29 (1421609395868925952)]} 0 0
[junit4:junit4]   2> 7382 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7383 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10029 (1421609395867877376)]} 0 6
[junit4:junit4]   2> 7385 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7386 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10030 (1421609395877314560)]} 0 1
[junit4:junit4]   2> 7387 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[29 (1421609395872071680)]} 0 6
[junit4:junit4]   2> 7393 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[30 (1421609395883606016)]} 0 1
[junit4:junit4]   2> 7395 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7397 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10030 (1421609395879411712)]} 0 9
[junit4:junit4]   2> 7400 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[10027 (-1421609395891994624)]} 0 0
[junit4:junit4]   2> 7406 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7410 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[10027 (-1421609395894091776)]} 0 8
[junit4:junit4]   2> 7411 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7413 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[30 (1421609395887800320)]} 0 17
[junit4:junit4]   2> 7414 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10031 (1421609395905626112)]} 0 1
[junit4:junit4]   2> 7416 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[27 (-1421609395908771840)]} 0 0
[junit4:junit4]   2> 7419 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7420 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10031 (1421609395908771840)]} 0 4
[junit4:junit4]   2> 7421 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7422 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[27 (-1421609395911917568)]} 0 3
[junit4:junit4]   2> 7423 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[10028 (-1421609395916111872)]} 0 0
[junit4:junit4]   2> 7424 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[31 (1421609395917160448)]} 0 0
[junit4:junit4]   2> 7428 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7429 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[10028 (-1421609395919257600)]} 0 3
[junit4:junit4]   2> 7431 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7433 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10032 (1421609395924500480)]} 0 2
[junit4:junit4]   2> 7434 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[31 (1421609395920306176)]} 0 7
[junit4:junit4]   2> 7437 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[28 (-1421609395930791936)]} 0 0
[junit4:junit4]   2> 7439 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7440 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10032 (1421609395929743360)]} 0 4
[junit4:junit4]   2> 7442 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7443 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[28 (-1421609395933937664)]} 0 3
[junit4:junit4]   2> 7444 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[10029 (-1421609395938131968)]} 0 0
[junit4:junit4]   2> 7445 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[32 (1421609395939180544)]} 0 0
[junit4:junit4]   2> 7450 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7452 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[32 (1421609395942326272)]} 0 4
[junit4:junit4]   2> 7459 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7459 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[29 (-1421609395953860608)]} 0 0
[junit4:junit4]   2> 7459 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[10029 (-1421609395943374848)]} 0 10
[junit4:junit4]   2> 7462 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10033 (1421609395957006336)]} 0 0
[junit4:junit4]   2> 7464 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7465 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[29 (-1421609395957006336)]} 0 3
[junit4:junit4]   2> 7468 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[33 (1421609395962249216)]} 0 1
[junit4:junit4]   2> 7468 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7468 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10033 (1421609395961200640)]} 0 3
[junit4:junit4]   2> 7471 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[10030 (-1421609395966443520)]} 0 0
[junit4:junit4]   2> 7472 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7473 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[33 (1421609395964346368)]} 0 4
[junit4:junit4]   2> 7475 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[30 (-1421609395970637824)]} 0 0
[junit4:junit4]   2> 7476 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7477 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[10030 (-1421609395969589248)]} 0 3
[junit4:junit4]   2> 7480 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10034 (1421609395974832128)]} 0 1
[junit4:junit4]   2> 7481 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7482 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[30 (-1421609395973783552)]} 0 4
[junit4:junit4]   2> 7485 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7485 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[34 (1421609395981123584)]} 0 0
[junit4:junit4]   2> 7487 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10034 (1421609395977977856)]} 0 5
[junit4:junit4]   2> 7490 T3001 C267 P50414 /update {wt=javabin&version=2} {delete=[10031 (-1421609395986366464)]} 0 0
[junit4:junit4]   2> 7494 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 7495 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[34 (1421609395985317888)]} 0 6
[junit4:junit4]   2> 7497 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7497 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[31 (-1421609395993706496)]} 0 0
[junit4:junit4]   2> 7498 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[10031 (-1421609395990560768)]} 0 4
[junit4:junit4]   2> 7500 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10035 (1421609395995803648)]} 0 0
[junit4:junit4]   2> 7501 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7502 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[31 (-1421609395995803648)]} 0 3
[junit4:junit4]   2> 7506 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[35 (1421609396001046528)]} 0 2
[junit4:junit4]   2> 7506 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7507 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10035 (1421609395998949376)]} 0 5
[junit4:junit4]   2> 7510 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[10033 (-1421609396007337984)]} 0 0
[junit4:junit4]   2> 7512 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7513 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[35 (1421609396006289408)]} 0 4
[junit4:junit4]   2> 7515 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[33 (-1421609396012580864)]} 0 0
[junit4:junit4]   2> 7516 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7517 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10033 (-1421609396010483712)]} 0 4
[junit4:junit4]   2> 7520 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7521 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10036 (1421609396016775168)]} 0 2
[junit4:junit4]   2> 7521 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[33 (-1421609396015726592)]} 0 3
[junit4:junit4]   2> 7524 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[36 (1421609396022018048)]} 0 0
[junit4:junit4]   2> 7526 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7527 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10036 (1421609396020969472)]} 0 4
[junit4:junit4]   2> 7529 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7529 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10037 (1421609396027260928)]} 0 0
[junit4:junit4]   2> 7530 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[36 (1421609396025163776)]} 0 3
[junit4:junit4]   2> 7533 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[37 (1421609396031455232)]} 0 0
[junit4:junit4]   2> 7536 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7536 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10037 (1421609396030406656)]} 0 4
[junit4:junit4]   2> 7539 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10038 (1421609396037746688)]} 0 0
[junit4:junit4]   2> 7542 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7542 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[37 (1421609396035649536)]} 0 5
[junit4:junit4]   2> 7546 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7546 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[38 (1421609396045086720)]} 0 0
[junit4:junit4]   2> 7547 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10038 (1421609396041940992)]} 0 4
[junit4:junit4]   2> 7550 T3001 C267 P50414 /update {wt=javabin&version=2} {delete=[10038 (-1421609396049281024)]} 0 0
[junit4:junit4]   2> 7552 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7554 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[38 (1421609396048232448)]} 0 5
[junit4:junit4]   2> 7556 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7556 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[10038 (-1421609396053475328)]} 0 2
[junit4:junit4]   2> 7556 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[38 (-1421609396055572480)]} 0 0
[junit4:junit4]   2> 7559 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10039 (1421609396057669632)]} 0 1
[junit4:junit4]   2> 7561 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7562 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[38 (-1421609396058718208)]} 0 3
[junit4:junit4]   2> 7564 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7564 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[39 (1421609396063961088)]} 0 0
[junit4:junit4]   2> 7565 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10039 (1421609396060815360)]} 0 4
[junit4:junit4]   2> 7568 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10040 (1421609396068155392)]} 0 0
[junit4:junit4]   2> 7571 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7571 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[39 (1421609396067106816)]} 0 4
[junit4:junit4]   2> 7574 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7575 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10040 (1421609396071301120)]} 0 4
[junit4:junit4]   2> 7576 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[40 (1421609396074446848)]} 0 2
[junit4:junit4]   2> 7583 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7583 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[40 (1421609396078641152)]} 0 5
[junit4:junit4]   2> 7626 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10041 (1421609396077592576)]} 0 49
[junit4:junit4]   2> 7627 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[41 (1421609396085981184)]} 0 42
[junit4:junit4]   2> 7634 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7634 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[41 (1421609396133167105)]} 0 4
[junit4:junit4]   2> 7638 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[40 (-1421609396141555712)]} 0 0
[junit4:junit4]   2> 7643 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7643 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[40 (-1421609396143652864)]} 0 3
[junit4:junit4]   2> 7646 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[42 (1421609396149944320)]} 0 0
[junit4:junit4]   2> 7650 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=17 
[junit4:junit4]   2> 7650 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10041 (1421609396133167104)]} 0 20
[junit4:junit4]   2> 7653 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[10040 (-1421609396157284352)]} 0 0
[junit4:junit4]   2> 7654 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 7655 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[42 (1421609396154138624)]} 0 5
[junit4:junit4]   2> 7657 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[43 (1421609396161478656)]} 0 0
[junit4:junit4]   2> 7659 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7660 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[10040 (-1421609396161478656)]} 0 3
[junit4:junit4]   2> 7662 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10042 (1421609396166721536)]} 0 0
[junit4:junit4]   2> 7663 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7664 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[43 (1421609396164624384)]} 0 4
[junit4:junit4]   2> 7667 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7669 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[44 (1421609396173012992)]} 0 1
[junit4:junit4]   2> 7670 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10042 (1421609396169867264)]} 0 5
[junit4:junit4]   2> 7672 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10043 (1421609396177207296)]} 0 0
[junit4:junit4]   2> 7675 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7676 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[44 (1421609396177207296)]} 0 4
[junit4:junit4]   2> 7679 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7679 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10043 (1421609396181401600)]} 0 3
[junit4:junit4]   2> 7679 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[42 (-1421609396184547328)]} 0 0
[junit4:junit4]   2> 7682 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[10044 (1421609396187693056)]} 0 0
[junit4:junit4]   2> 7684 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7685 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[42 (-1421609396187693056)]} 0 3
[junit4:junit4]   2> 7687 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[45 (1421609396192935936)]} 0 0
[junit4:junit4]   2> 7689 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7690 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10044 (1421609396190838784)]} 0 5
[junit4:junit4]   2> 7692 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10042 (-1421609396198178816)]} 0 0
[junit4:junit4]   2> 7694 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7695 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[45 (1421609396197130240)]} 0 4
[junit4:junit4]   2> 7697 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7698 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[10042 (-1421609396201324544)]} 0 3
[junit4:junit4]   2> 7698 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[43 (-1421609396204470272)]} 0 0
[junit4:junit4]   2> 7701 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10045 (1421609396206567424)]} 0 1
[junit4:junit4]   2> 7702 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7703 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[43 (-1421609396207616000)]} 0 2
[junit4:junit4]   2> 7706 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7707 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10045 (1421609396209713152)]} 0 4
[junit4:junit4]   2> 7708 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[46 (1421609396213907456)]} 0 1
[junit4:junit4]   2> 7711 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[10043 (-1421609396218101760)]} 0 0
[junit4:junit4]   2> 7714 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7715 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7715 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[46 (1421609396218101760)]} 0 4
[junit4:junit4]   2> 7716 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[10043 (-1421609396220198912)]} 0 3
[junit4:junit4]   2> 7718 T3001 C267 P50414 /update {wt=javabin&version=2} {delete=[45 (-1421609396225441792)]} 0 0
[junit4:junit4]   2> 7719 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10046 (1421609396226490368)]} 0 0
[junit4:junit4]   2> 7723 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7725 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[45 (-1421609396228587520)]} 0 4
[junit4:junit4]   2> 7726 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7727 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10046 (1421609396229636096)]} 0 5
[junit4:junit4]   2> 7728 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[47 (1421609396234878976)]} 0 1
[junit4:junit4]   2> 7729 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[10045 (-1421609396236976128)]} 0 0
[junit4:junit4]   2> 7733 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7733 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[47 (1421609396238024704)]} 0 3
[junit4:junit4]   2> 7734 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7734 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10045 (-1421609396239073280)]} 0 3
[junit4:junit4]   2> 7736 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[47 (-1421609396244316160)]} 0 0
[junit4:junit4]   2> 7738 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[10047 (1421609396246413312)]} 0 0
[junit4:junit4]   2> 7742 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7743 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[47 (-1421609396248510464)]} 0 3
[junit4:junit4]   2> 7744 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7745 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10047 (1421609396249559040)]} 0 4
[junit4:junit4]   2> 7746 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[48 (1421609396253753344)]} 0 1
[junit4:junit4]   2> 7748 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10047 (-1421609396256899072)]} 0 0
[junit4:junit4]   2> 7751 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7752 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[48 (1421609396256899072)]} 0 4
[junit4:junit4]   2> 7753 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7754 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[10047 (-1421609396260044800)]} 0 3
[junit4:junit4]   2> 7755 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[49 (1421609396264239104)]} 0 0
[junit4:junit4]   2> 7756 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10048 (1421609396265287680)]} 0 0
[junit4:junit4]   2> 7760 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7761 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[49 (1421609396267384832)]} 0 3
[junit4:junit4]   2> 7761 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7763 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10048 (1421609396268433408)]} 0 4
[junit4:junit4]   2> 7764 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[49 (-1421609396273676288)]} 0 0
[junit4:junit4]   2> 7765 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[10049 (1421609396274724864)]} 0 0
[junit4:junit4]   2> 7769 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7770 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[49 (-1421609396276822016)]} 0 3
[junit4:junit4]   2> 7772 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7772 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[50 (1421609396282064896)]} 0 0
[junit4:junit4]   2> 7772 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10049 (1421609396277870592)]} 0 4
[junit4:junit4]   2> 7775 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10049 (-1421609396285210624)]} 0 0
[junit4:junit4]   2> 7778 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7780 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7780 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[50 (1421609396285210624)]} 0 5
[junit4:junit4]   2> 7781 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10049 (-1421609396288356352)]} 0 3
[junit4:junit4]   2> 7784 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[51 (1421609396293599233)]} 0 1
[junit4:junit4]   2> 7784 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10050 (1421609396293599232)]} 0 1
[junit4:junit4]   2> 7790 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7790 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7790 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10050 (1421609396297793536)]} 0 3
[junit4:junit4]   2> 7791 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[51 (1421609396297793537)]} 0 4
[junit4:junit4]   2> 7793 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10051 (1421609396304084992)]} 0 0
[junit4:junit4]   2> 7793 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[52 (1421609396304084993)]} 0 0
[junit4:junit4]   2> 7800 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7801 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10051 (1421609396308279296)]} 0 4
[junit4:junit4]   2> 7802 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 7803 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[52 (1421609396308279297)]} 0 6
[junit4:junit4]   2> 7805 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10052 (1421609396316667904)]} 0 1
[junit4:junit4]   2> 7806 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[53 (1421609396317716480)]} 0 0
[junit4:junit4]   2> 7815 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7816 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[53 (1421609396322959360)]} 0 5
[junit4:junit4]   2> 7816 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7817 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10052 (1421609396322959361)]} 0 6
[junit4:junit4]   2> 7819 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[54 (1421609396331347968)]} 0 1
[junit4:junit4]   2> 7820 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10053 (1421609396332396544)]} 0 1
[junit4:junit4]   2> 7826 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7827 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7827 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[54 (1421609396335542272)]} 0 4
[junit4:junit4]   2> 7827 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10053 (1421609396335542273)]} 0 4
[junit4:junit4]   2> 7830 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[53 (-1421609396342882304)]} 0 0
[junit4:junit4]   2> 7831 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10054 (1421609396342882305)]} 0 1
[junit4:junit4]   2> 7835 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7836 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[53 (-1421609396346028033)]} 0 3
[junit4:junit4]   2> 7837 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7838 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[10054 (1421609396346028032)]} 0 5
[junit4:junit4]   2> 7838 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[55 (1421609396351270912)]} 0 0
[junit4:junit4]   2> 7840 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10053 (-1421609396353368064)]} 0 0
[junit4:junit4]   2> 7844 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7845 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[55 (1421609396354416640)]} 0 4
[junit4:junit4]   2> 7846 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7847 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[10053 (-1421609396356513792)]} 0 4
[junit4:junit4]   2> 7848 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[56 (1421609396360708096)]} 0 1
[junit4:junit4]   2> 7848 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10055 (1421609396361756672)]} 0 0
[junit4:junit4]   2> 7854 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7855 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[56 (1421609396363853824)]} 0 5
[junit4:junit4]   2> 7856 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7856 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10055 (1421609396365950976)]} 0 4
[junit4:junit4]   2> 7858 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[55 (-1421609396372242432)]} 0 0
[junit4:junit4]   2> 7859 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10056 (1421609396373291008)]} 0 0
[junit4:junit4]   2> 7863 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7864 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[55 (-1421609396375388160)]} 0 3
[junit4:junit4]   2> 7867 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 7867 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[57 (1421609396380631040)]} 0 1
[junit4:junit4]   2> 7867 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[10056 (1421609396376436736)]} 0 5
[junit4:junit4]   2> 7871 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10055 (-1421609396385873920)]} 0 0
[junit4:junit4]   2> 7874 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7874 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[57 (1421609396383776768)]} 0 5
[junit4:junit4]   2> 7876 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7876 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[10055 (-1421609396389019648)]} 0 2
[junit4:junit4]   2> 7876 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[56 (-1421609396391116800)]} 0 0
[junit4:junit4]   2> 7879 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10057 (1421609396393213952)]} 0 1
[junit4:junit4]   2> 7881 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7882 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[56 (-1421609396394262528)]} 0 3
[junit4:junit4]   2> 7884 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7884 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[58 (1421609396399505408)]} 0 0
[junit4:junit4]   2> 7885 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10057 (1421609396396359680)]} 0 4
[junit4:junit4]   2> 7888 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[10056 (-1421609396403699712)]} 0 0
[junit4:junit4]   2> 7894 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 7895 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[58 (1421609396402651136)]} 0 8
[junit4:junit4]   2> 7897 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7899 T3025 C266 P50426 /update {wt=javabin&version=2} {delete=[10056 (-1421609396411039744)]} 0 4
[junit4:junit4]   2> 7900 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[59 (1421609396416282624)]} 0 0
[junit4:junit4]   2> 7908 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10058 (1421609396417331200)]} 0 7
[junit4:junit4]   2> 7912 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7913 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[59 (1421609396426768384)]} 0 3
[junit4:junit4]   2> 7916 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[60 (1421609396433059840)]} 0 0
[junit4:junit4]   2> 7918 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7920 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10058 (1421609396430962688)]} 0 6
[junit4:junit4]   2> 7923 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10059 (1421609396439351296)]} 0 1
[junit4:junit4]   2> 7923 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7924 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[60 (1421609396437254144)]} 0 4
[junit4:junit4]   2> 7927 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7927 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[61 (1421609396443545600)]} 0 1
[junit4:junit4]   2> 7928 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[10059 (1421609396442497024)]} 0 3
[junit4:junit4]   2> 7932 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10060 (1421609396448788480)]} 0 1
[junit4:junit4]   2> 7934 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7935 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[61 (1421609396447739904)]} 0 5
[junit4:junit4]   2> 7938 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7938 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[10060 (1421609396451934208)]} 0 4
[junit4:junit4]   2> 7939 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[62 (1421609396457177088)]} 0 0
[junit4:junit4]   2> 7941 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10061 (1421609396459274240)]} 0 0
[junit4:junit4]   2> 7949 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 7949 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10061 (1421609396462419968)]} 0 5
[junit4:junit4]   2> 7950 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7951 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10062 (1421609396469760000)]} 0 0
[junit4:junit4]   2> 7953 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[62 (1421609396463468544)]} 0 8
[junit4:junit4]   2> 7955 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[61 (-1421609396473954304)]} 0 0
[junit4:junit4]   2> 7956 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7957 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10062 (1421609396472905728)]} 0 3
[junit4:junit4]   2> 7960 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7961 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[10061 (-1421609396480245760)]} 0 0
[junit4:junit4]   2> 7962 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[61 (-1421609396476051456)]} 0 5
[junit4:junit4]   2> 7963 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[63 (1421609396482342912)]} 0 0
[junit4:junit4]   2> 7965 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7966 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[10061 (-1421609396482342912)]} 0 3
[junit4:junit4]   2> 7968 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10063 (1421609396487585792)]} 0 0
[junit4:junit4]   2> 7969 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7971 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[63 (1421609396486537216)]} 0 4
[junit4:junit4]   2> 7973 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7974 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10063 (1421609396490731520)]} 0 3
[junit4:junit4]   2> 7974 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[62 (-1421609396493877248)]} 0 0
[junit4:junit4]   2> 7976 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[10062 (-1421609396495974400)]} 0 0
[junit4:junit4]   2> 7978 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7979 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[62 (-1421609396495974400)]} 0 3
[junit4:junit4]   2> 7980 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7981 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10062 (-1421609396498071552)]} 0 3
[junit4:junit4]   2> 7982 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[64 (1421609396501217280)]} 0 1
[junit4:junit4]   2> 7983 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[10064 (1421609396503314432)]} 0 0
[junit4:junit4]   2> 7986 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7987 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[64 (1421609396503314432)]} 0 4
[junit4:junit4]   2> 7988 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7990 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[64 (-1421609396510654464)]} 0 0
[junit4:junit4]   2> 7990 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10064 (1421609396505411584)]} 0 5
[junit4:junit4]   2> 7992 T3001 C267 P50414 /update {wt=javabin&version=2} {delete=[10064 (-1421609396512751616)]} 0 0
[junit4:junit4]   2> 7994 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7995 T3025 C266 P50426 /update {wt=javabin&version=2} {delete=[64 (-1421609396511703040)]} 0 4
[junit4:junit4]   2> 7996 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 7996 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[65 (1421609396516945920)]} 0 0
[junit4:junit4]   2> 7997 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[10064 (-1421609396515897344)]} 0 2
[junit4:junit4]   2> 8000 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10065 (1421609396520091648)]} 0 1
[junit4:junit4]   2> 8002 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8003 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[65 (1421609396520091648)]} 0 4
[junit4:junit4]   2> 8005 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[66 (1421609396526383104)]} 0 0
[junit4:junit4]   2> 8007 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8007 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10065 (1421609396524285952)]} 0 4
[junit4:junit4]   2> 8010 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[10066 (1421609396531625984)]} 0 0
[junit4:junit4]   2> 8010 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8011 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[66 (1421609396529528832)]} 0 3
[junit4:junit4]   2> 8014 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[67 (1421609396535820288)]} 0 0
[junit4:junit4]   2> 8016 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8016 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10066 (1421609396533723136)]} 0 4
[junit4:junit4]   2> 8019 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10067 (1421609396540014592)]} 0 1
[junit4:junit4]   2> 8020 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8020 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[67 (1421609396537917440)]} 0 4
[junit4:junit4]   2> 8023 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[68 (1421609396545257472)]} 0 0
[junit4:junit4]   2> 8023 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8024 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10067 (1421609396543160320)]} 0 3
[junit4:junit4]   2> 8026 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10068 (1421609396548403200)]} 0 0
[junit4:junit4]   2> 8028 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8029 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[68 (1421609396548403200)]} 0 3
[junit4:junit4]   2> 8031 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8031 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10068 (1421609396551548928)]} 0 2
[junit4:junit4]   2> 8031 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[66 (-1421609396553646080)]} 0 0
[junit4:junit4]   2> 8034 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[10066 (-1421609396556791808)]} 0 0
[junit4:junit4]   2> 8036 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8036 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[66 (-1421609396556791808)]} 0 2
[junit4:junit4]   2> 8038 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8039 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[10066 (-1421609396558888960)]} 0 3
[junit4:junit4]   2> 8039 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[69 (1421609396562034688)]} 0 0
[junit4:junit4]   2> 8041 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10069 (1421609396564131840)]} 0 0
[junit4:junit4]   2> 8045 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8046 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[69 (1421609396566228992)]} 0 3
[junit4:junit4]   2> 8047 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8047 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10069 (1421609396566228993)]} 0 4
[junit4:junit4]   2> 8048 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[67 (-1421609396571471872)]} 0 0
[junit4:junit4]   2> 8050 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[10067 (-1421609396573569024)]} 0 0
[junit4:junit4]   2> 8052 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8053 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[67 (-1421609396573569024)]} 0 3
[junit4:junit4]   2> 8054 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8055 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10067 (-1421609396575666176)]} 0 3
[junit4:junit4]   2> 8056 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[70 (1421609396578811904)]} 0 1
[junit4:junit4]   2> 8059 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10070 (1421609396580909056)]} 0 2
[junit4:junit4]   2> 8061 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8061 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[70 (1421609396580909056)]} 0 4
[junit4:junit4]   2> 8063 T3002 C267 P50414 /update {wt=javabin&version=2} {delete=[68 (-1421609396587200512)]} 0 0
[junit4:junit4]   2> 8063 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8064 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10070 (1421609396585103360)]} 0 3
[junit4:junit4]   2> 8067 T3004 C267 P50414 /update {wt=javabin&version=2} {delete=[10068 (-1421609396591394816)]} 0 0
[junit4:junit4]   2> 8069 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8070 T3025 C266 P50426 /update {wt=javabin&version=2} {delete=[68 (-1421609396590346240)]} 0 4
[junit4:junit4]   2> 8071 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[71 (1421609396595589120)]} 0 0
[junit4:junit4]   2> 8072 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8073 T3022 C266 P50426 /update {wt=javabin&version=2} {delete=[10068 (-1421609396594540544)]} 0 3
[junit4:junit4]   2> 8075 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10071 (1421609396599783424)]} 0 0
[junit4:junit4]   2> 8077 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8078 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[71 (1421609396598734848)]} 0 4
[junit4:junit4]   2> 8080 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8081 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[72 (1421609396605026304)]} 0 1
[junit4:junit4]   2> 8081 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[10071 (1421609396601880576)]} 0 4
[junit4:junit4]   2> 8083 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10072 (1421609396608172032)]} 0 0
[junit4:junit4]   2> 8086 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8086 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[72 (1421609396608172032)]} 0 3
[junit4:junit4]   2> 8089 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[73 (1421609396614463488)]} 0 0
[junit4:junit4]   2> 8090 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8090 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10072 (1421609396611317760)]} 0 4
[junit4:junit4]   2> 8092 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10073 (1421609396617609216)]} 0 0
[junit4:junit4]   2> 8095 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8095 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[73 (1421609396616560640)]} 0 4
[junit4:junit4]   2> 8097 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[69 (-1421609396622852096)]} 0 0
[junit4:junit4]   2> 8097 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8098 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10073 (1421609396621803520)]} 0 2
[junit4:junit4]   2> 8101 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[10069 (-1421609396627046400)]} 0 0
[junit4:junit4]   2> 8103 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8103 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[69 (-1421609396625997824)]} 0 3
[junit4:junit4]   2> 8105 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8105 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[74 (1421609396631240704)]} 0 0
[junit4:junit4]   2> 8106 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10069 (-1421609396629143552)]} 0 3
[junit4:junit4]   2> 8108 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10074 (1421609396634386432)]} 0 0
[junit4:junit4]   2> 8110 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8110 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[74 (1421609396634386432)]} 0 2
[junit4:junit4]   2> 8113 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8113 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[75 (1421609396639629312)]} 0 0
[junit4:junit4]   2> 8114 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10074 (1421609396636483584)]} 0 4
[junit4:junit4]   2> 8118 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10075 (1421609396643823616)]} 0 1
[junit4:junit4]   2> 8119 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8119 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[75 (1421609396642775040)]} 0 3
[junit4:junit4]   2> 8122 T3003 C267 P50414 /update {wt=javabin&version=2} {delete=[70 (-1421609396649066496)]} 0 0
[junit4:junit4]   2> 8123 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8124 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10075 (1421609396646969344)]} 0 4
[junit4:junit4]   2> 8127 T3005 C267 P50414 /update {wt=javabin&version=2} {delete=[10070 (-1421609396654309376)]} 0 0
[junit4:junit4]   2> 8128 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8129 T3021 C266 P50426 /update {wt=javabin&version=2} {delete=[70 (-1421609396651163648)]} 0 5
[junit4:junit4]   2> 8132 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8133 T3020 C266 P50426 /update {wt=javabin&version=2} {delete=[10070 (-1421609396657455104)]} 0 3
[junit4:junit4]   2> 8143 T3006 C267 P50414 /update {wt=javabin&version=2} {add=[76 (1421609396657455104)]} 0 13
[junit4:junit4]   2> 8144 T3001 C267 P50414 /update {wt=javabin&version=2} {add=[10076 (1421609396662697984)]} 0 9
[junit4:junit4]   2> 8150 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8150 T3024 C266 P50426 /update {wt=javabin&version=2} {add=[76 (1421609396673183744)]} 0 5
[junit4:junit4]   2> 8150 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8151 T3023 C266 P50426 /update {wt=javabin&version=2} {add=[10076 (1421609396675280896)]} 0 4
[junit4:junit4]   2> 8152 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[77 (1421609396680523776)]} 0 0
[junit4:junit4]   2> 8154 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[10077 (1421609396682620928)]} 0 0
[junit4:junit4]   2> 8158 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8180 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8180 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[10077 (1421609396685766656)]} 0 23
[junit4:junit4]   2> 8181 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[77 (1421609396683669504)]} 0 26
[junit4:junit4]   2> 8184 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[10078 (1421609396713029632)]} 0 1
[junit4:junit4]   2> 8184 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[78 (1421609396714078208)]} 0 0
[junit4:junit4]   2> 8194 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8196 T3040 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8196 T3020 C266 P50426 /update {wt=javabin&version=2} {add=[78 (1421609396722466816)]} 0 4
[junit4:junit4]   2> 8197 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10078 (1421609396716175360)]} 0 11
[junit4:junit4]   2> 8198 T3006 C267 P50414 /update {wt=javabin&version=2} {delete=[71 (-1421609396728758272)]} 0 0
[junit4:junit4]   2> 8199 T3001 C267 P50414 /update {wt=javabin&version=2} {delete=[10071 (-1421609396729806848)]} 0 0
[junit4:junit4]   2> 8204 T3036 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8204 T3038 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8204 T3023 C266 P50426 /update {wt=javabin&version=2} {delete=[10071 (-1421609396732952576)]} 0 2
[junit4:junit4]   2> 8204 T3024 C266 P50426 /update {wt=javabin&version=2} {delete=[71 (-1421609396731904000)]} 0 3
[junit4:junit4]   2> 8208 T3002 C267 P50414 /update {wt=javabin&version=2} {add=[10079 (1421609396738195456)]} 0 1
[junit4:junit4]   2> 8208 T3004 C267 P50414 /update {wt=javabin&version=2} {add=[79 (1421609396738195457)]} 0 1
[junit4:junit4]   2> 8212 T3037 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 8213 T3039 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8213 T3022 C266 P50426 /update {wt=javabin&version=2} {add=[79 (1421609396741341184)]} 0 3
[junit4:junit4]   2> 8214 T3025 C266 P50426 /update {wt=javabin&version=2} {add=[10079 (1421609396741341185)]} 0 4
[junit4:junit4]   2> 8217 T3005 C267 P50414 /update {wt=javabin&version=2} {add=[10080 (1421609396747632641)]} 0 1
[junit4:junit4]   2> 8217 T3003 C267 P50414 /update {wt=javabin&version=2} {add=[80 (1421609396747632640)]} 0 1
[junit4:junit4]   2> 8222 T3035 C265 P50435 REQ /update {distrib.from=http://127.0.0.1:50426/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 8222 T3021 C266 P50426 /update {wt=javabin&version=2} {add=[10080 (1421609396749729792)]} 0 4
[junit4:junit4]   2> 8223 T3

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

cc.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> 21219 T3029 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 21219 T3029 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 21219 T3093 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 21219 T3093 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 21221 T2988 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4]   2> 21221 T2988 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4]   2> 21221 T2988 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4]   2> 21222 T2988 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4]   2> 21222 T2988 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4]   2> 21222 T2988 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 50414
[junit4:junit4]   2> 21217 T3010 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 21228 T3010 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2\index.20121217065251105\lucene-61c6c95e-write.lock FAILED !!!!!
[junit4:junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2\index.20121217065251105 FAILED !!!!!
[junit4:junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428\jetty2 FAILED !!!!!
[junit4:junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1355752361428 FAILED !!!!!
[junit4:junit4]   2> 21306 T2988 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 21308 T2988 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=Lucene3x, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=uk_UA, timezone=America/Denver
[junit4:junit4]   2> NOTE: Windows 7 6.1 amd64/Sun Microsystems Inc. 1.6.0_37 (64-bit)/cpus=2,threads=1,free=153063696,total=506232832
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestPerFieldSimilarity, TestSystemIdResolver, MultiTermTest, SolrInfoMBeanTest, BasicFunctionalityTest, DirectSolrConnectionTest, TestDistributedSearch, DisMaxRequestHandlerTest, HighlighterConfigTest, TestMergePolicyConfig, SignatureUpdateProcessorFactoryTest, PingRequestHandlerTest, TestSolr4Spatial, TestWordDelimiterFilterFactory, DirectUpdateHandlerTest, CopyFieldTest, TestAtomicUpdateErrorCases, ExternalFileFieldSortTest, XsltUpdateRequestHandlerTest, CurrencyFieldTest, AlternateDirectoryTest, SimpleFacetsTest, SpatialFilterTest, ReturnFieldsTest, DirectSolrSpellCheckerTest, OverseerTest, UUIDFieldTest, ClusterStateUpdateTest, SolrCoreTest, StatsComponentTest, SpellCheckComponentTest, SolrIndexConfigTest, TestAnalyzedSuggestions, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, BinaryUpdateRequestHandlerTest, TestReload, TestCoreContainer, FullSolrCloudDistribCmdsTest, NumericFieldsTest, DefaultValueUpdateProcessorTest, TestDefaultSimilarityFactory, TestCollationKeyRangeQueries, TestReversedWildcardFilterFactory, TestRealTimeGet, DistributedSpellCheckComponentTest, TestSolrCoreProperties, TestReplicationHandler, TestQuerySenderListener, RequiredFieldsTest, FieldMutatingUpdateProcessorTest, TestStressLucene, TestUtils, TestQueryUtils, HighlighterTest, TestBinaryField, WordBreakSolrSpellCheckerTest, TestBadConfig, SearchHandlerTest, NotRequiredUniqueKeyTest, LegacyHTMLStripCharFilterTest, TestQuerySenderNoQuery, PreAnalyzedFieldTest, BasicZkTest, TestFaceting, TestFoldingMultitermQuery, TestSort, SortByFunctionTest, SuggesterWFSTTest, LeaderElectionTest, SuggesterFSTTest, IndexReaderFactoryTest, DateMathParserTest, ShardRoutingTest, SuggesterTest, TestPropInject, TestBinaryResponseWriter, PeerSyncTest, CoreContainerCoreInitFailuresTest, SolrRequestParserTest, TestJmxMonitoredMap, TestLFUCache, TestRTGBase, TestDocSet, TestPluginEnable, TestFiltering, CacheHeaderTest, TimeZoneUtilsTest, CircularListTest, MinimalSchemaTest, SpellPossibilityIteratorTest, TestBM25SimilarityFactory, LukeRequestHandlerTest, FastVectorHighlighterTest, UniqFieldsUpdateProcessorFactoryTest, TestJoin, PluginInfoTest, ZkNodePropsTest, DistributedQueryElevationComponentTest, TestIndexingPerformance, CSVRequestHandlerTest, TestXIncludeConfig, MoreLikeThisHandlerTest, FileBasedSpellCheckerTest, TestArbitraryIndexDir, DistanceFunctionTest, TestCSVResponseWriter, TestFastLRUCache, SimplePostToolTest, TestMultiCoreConfBootstrap, RequestHandlersTest, SpellCheckCollatorTest, TestRangeQuery, RAMDirectoryFactoryTest, DistributedMLTComponentTest, BasicDistributedZkTest, RecoveryZkTest]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RecoveryZkTest -Dtests.seed=E9DD10EF2468392C -Dtests.slow=true -Dtests.locale=uk_UA -Dtests.timezone=America/Denver -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR   0.00s | RecoveryZkTest (suite) <<<
[junit4:junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=3047, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([E9DD10EF2468392C]:0)
[junit4:junit4]    > 	at java.lang.Thread.getStackTrace(Thread.java:1479)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
[junit4:junit4]    > 	at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:517)
[junit4:junit4]    > 	at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:983)
[junit4:junit4]    > 	at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:875)
[junit4:junit4]    > 	at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:867)
[junit4:junit4]    > 	at org.apache.solr.core.MockDirectoryFactory.create(MockDirectoryFactory.java:33)
[junit4:junit4]    > 	at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:256)
[junit4:junit4]    > 	at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:212)
[junit4:junit4]    > 	at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:376)
[junit4:junit4]    > 	at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:273)
[junit4:junit4]    > 	at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:153)
[junit4:junit4]    > 	at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:408)
[junit4:junit4]    > 	at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:223)
[junit4:junit4]    > Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\index1587515882tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@5610e743)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.lucene.util.CloseableDirectory.close(CloseableDirectory.java:47)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:602)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:599)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedContext.closeResources(RandomizedContext.java:167)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$2.afterAlways(RandomizedRunner.java:615)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] Completed in 21.52s, 1 test, 1 error <<< FAILURES!

[...truncated 378 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:353: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:178: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:438: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1175: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:840: There were test failures: 242 suites, 1009 tests, 1 suite-level error, 12 ignored (7 assumptions)

Total time: 43 minutes 42 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jdk1.6.0_37 -XX:+UseSerialGC
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message