lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 1146 - Failure
Date Fri, 21 Dec 2012 00:47:00 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/1146/

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=1170, name=coreLoadExecutor-528-thread-1, 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=1170, name=coreLoadExecutor-528-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
	at __randomizedtesting.SeedInfo.seed([A685A2C3C44081CA]:0)
	at java.lang.Thread.getStackTrace(Thread.java:1495)
	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:977)
	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:267)
	at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:223)
	at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:239)
	at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:444)
	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:713)
	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:602)
	at org.apache.solr.core.CoreContainer.createFromZk(CoreContainer.java:947)
	at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1029)
	at org.apache.solr.core.CoreContainer$3.call(CoreContainer.java:627)
	at org.apache.solr.core.CoreContainer$3.call(CoreContainer.java:622)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
Caused by: java.lang.AssertionError: Directory not closed: BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1f54e65e lockFactory=org.apache.lucene.store.NativeFSLockFactory@31d137a8)
	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)
	... 1 more




Build Log:
[...truncated 8293 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4]   2> 0 T1045 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 4 T1045 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-RecoveryZkTest-1356050093024
[junit4:junit4]   2> 5 T1045 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 5 T1046 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 8 T1046 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 8 T1046 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 8 T1046 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 8 T1046 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 9 T1046 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 106 T1045 oasc.ZkTestServer.run start zk server on port:52036
[junit4:junit4]   2> 106 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@77fd070c
[junit4:junit4]   2> 107 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 108 T1051 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 108 T1051 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 108 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52037
[junit4:junit4]   2> 109 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52037
[junit4:junit4]   2> 109 T1049 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 119 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40000 with negotiated timeout 10000 for client /140.211.11.196:52037
[junit4:junit4]   2> 119 T1051 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40000, negotiated timeout = 10000
[junit4:junit4]   2> 119 T1052 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77fd070c name:ZooKeeperConnection Watcher:127.0.0.1:52036 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 120 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 120 T1045 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 131 T1050 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13bbae253e40000
[junit4:junit4]   2> 139 T1052 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 139 T1047 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:52037 which had sessionid 0x13bbae253e40000
[junit4:junit4]   2> 139 T1045 oaz.ZooKeeper.close Session: 0x13bbae253e40000 closed
[junit4:junit4]   2> 140 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@41441992
[junit4:junit4]   2> 141 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 141 T1053 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 142 T1053 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 142 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52038
[junit4:junit4]   2> 142 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52038
[junit4:junit4]   2> 151 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40001 with negotiated timeout 10000 for client /140.211.11.196:52038
[junit4:junit4]   2> 151 T1053 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40001, negotiated timeout = 10000
[junit4:junit4]   2> 151 T1054 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41441992 name:ZooKeeperConnection Watcher:127.0.0.1:52036/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 151 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 152 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 166 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 178 T1045 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 186 T1045 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 201 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 202 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 225 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 226 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 329 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 330 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 339 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 340 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 350 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 351 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 361 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 362 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 369 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 370 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 380 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 381 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 389 T1045 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 389 T1045 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 397 T1050 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13bbae253e40001
[junit4:junit4]   2> 407 T1054 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 407 T1047 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:52038 which had sessionid 0x13bbae253e40001
[junit4:junit4]   2> 407 T1045 oaz.ZooKeeper.close Session: 0x13bbae253e40001 closed
[junit4:junit4]   2> 523 T1045 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 528 T1045 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52039
[junit4:junit4]   2> 528 T1045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 529 T1045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427
[junit4:junit4]   2> 529 T1045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/'
[junit4:junit4]   2> 558 T1045 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 558 T1045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 559 T1045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427
[junit4:junit4]   2> 559 T1045 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/solr.xml
[junit4:junit4]   2> 560 T1045 oasc.CoreContainer.<init> New CoreContainer 1390334492
[junit4:junit4]   2> 560 T1045 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/'
[junit4:junit4]   2> 561 T1045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/'
[junit4:junit4]   2> 577 T1045 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4]   2> 578 T1045 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 578 T1045 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 579 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 579 T1045 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 579 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 580 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 580 T1045 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 581 T1045 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 581 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4]   2> 596 T1045 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 610 T1045 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:52036/solr
[junit4:junit4]   2> 611 T1045 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 611 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@6dacb14f
[junit4:junit4]   2> 612 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 612 T1064 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 613 T1064 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 613 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52040
[junit4:junit4]   2> 613 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52040
[junit4:junit4]   2> 615 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40002 with negotiated timeout 20000 for client /140.211.11.196:52040
[junit4:junit4]   2> 615 T1064 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40002, negotiated timeout = 20000
[junit4:junit4]   2> 615 T1065 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dacb14f name:ZooKeeperConnection Watcher:127.0.0.1:52036 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 615 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 616 T1050 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13bbae253e40002
[junit4:junit4]   2> 621 T1065 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 621 T1047 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:52040 which had sessionid 0x13bbae253e40002
[junit4:junit4]   2> 621 T1045 oaz.ZooKeeper.close Session: 0x13bbae253e40002 closed
[junit4:junit4]   2> 622 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4]   2> 638 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b41c865
[junit4:junit4]   2> 640 T1066 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 640 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 641 T1066 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 641 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52041
[junit4:junit4]   2> 641 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52041
[junit4:junit4]   2> 643 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40003 with negotiated timeout 20000 for client /140.211.11.196:52041
[junit4:junit4]   2> 643 T1066 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40003, negotiated timeout = 20000
[junit4:junit4]   2> 643 T1067 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b41c865 name:ZooKeeperConnection Watcher:127.0.0.1:52036/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 643 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 647 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 658 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 668 T1045 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52039_
[junit4:junit4]   2> 669 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:delete cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:52039_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:52039_
[junit4:junit4]   2> 679 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52039_
[junit4:junit4]   2> 688 T1045 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 711 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 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> 712 T1045 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 715 T1045 oasc.Overseer.start Overseer (id=88870098896683011-127.0.0.1:52039_-n_0000000000) starting
[junit4:junit4]   2> 716 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 719 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 730 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 731 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 738 T1069 oasc.OverseerCollectionProcessor.run Process current queue of collection messages
[junit4:junit4]   2> 739 T1045 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 742 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 745 T1068 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 751 T1070 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/collection1
[junit4:junit4]   2> 751 T1070 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 752 T1070 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 752 T1070 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 754 T1070 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/collection1/'
[junit4:junit4]   2> 755 T1070 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 756 T1070 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/collection1/lib/README' to classloader
[junit4:junit4]   2> 817 T1070 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 889 T1070 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 990 T1070 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 997 T1070 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1647 T1070 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1660 T1070 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1664 T1070 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1681 T1070 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1686 T1070 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1691 T1070 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1692 T1070 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1693 T1070 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1356050093427/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data/
[junit4:junit4]   2> 1694 T1070 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40363068
[junit4:junit4]   2> 1694 T1070 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1695 T1070 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data forceNew:false
[junit4:junit4]   2> 1695 T1070 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data
[junit4:junit4]   2> 1696 T1070 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data/index/
[junit4:junit4]   2> 1697 T1070 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1697 T1070 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data/index forceNew:false
[junit4:junit4]   2> 1701 T1070 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@3fa3342c lockFactory=org.apache.lucene.store.NativeFSLockFactory@479cfe1a)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1701 T1070 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1702 T1070 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data/index
[junit4:junit4]   2> 1702 T1070 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1704 T1070 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1704 T1070 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1704 T1070 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1705 T1070 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1706 T1070 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1706 T1070 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1706 T1070 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1707 T1070 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1708 T1070 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1709 T1070 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1709 T1070 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1710 T1070 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1711 T1070 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1711 T1070 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1711 T1070 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1712 T1070 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1713 T1070 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1714 T1070 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1714 T1070 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1715 T1070 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1716 T1070 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1717 T1070 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1717 T1070 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1718 T1070 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1719 T1070 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1720 T1070 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1732 T1070 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1739 T1070 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1741 T1070 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> 1744 T1070 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data
[junit4:junit4]   2> 1744 T1070 oass.SolrIndexSearcher.<init> Opening Searcher@cd7d0bc main
[junit4:junit4]   2> 1746 T1070 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1746 T1070 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1746 T1070 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1765 T1070 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1858 T1071 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cd7d0bc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1861 T1070 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1862 T1070 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1862 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x56 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 2253 T1068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2254 T1068 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:52039_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52039"}
[junit4:junit4]   2> 2254 T1068 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2254 T1068 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2255 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x5e zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2287 T1067 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> 2875 T1070 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2875 T1070 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52039 collection:control_collection shard:shard1
[junit4:junit4]   2> 2876 T1070 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2896 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:delete cxid:0x7b 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> 2898 T1070 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2898 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x7c zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2907 T1070 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2908 T1070 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2908 T1070 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52039/collection1/
[junit4:junit4]   2> 2908 T1070 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2909 T1070 oasc.SyncStrategy.syncToMe http://127.0.0.1:52039/collection1/ has no replicas
[junit4:junit4]   2> 2909 T1070 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52039/collection1/
[junit4:junit4]   2> 2909 T1070 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2914 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40003 type:create cxid:0x86 zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3303 T1068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3326 T1067 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> 3384 T1070 oasc.ZkController.register We are http://127.0.0.1:52039/collection1/ and leader is http://127.0.0.1:52039/collection1/
[junit4:junit4]   2> 3384 T1070 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52039
[junit4:junit4]   2> 3384 T1070 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3385 T1070 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3385 T1070 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3394 T1070 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3396 T1045 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4]   2> 3397 T1045 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3397 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3414 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3426 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3f3c80e5
[junit4:junit4]   2> 3427 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3427 T1072 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3428 T1072 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 3428 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52046
[junit4:junit4]   2> 3428 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52046
[junit4:junit4]   2> 3430 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40004 with negotiated timeout 10000 for client /140.211.11.196:52046
[junit4:junit4]   2> 3430 T1072 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40004, negotiated timeout = 10000
[junit4:junit4]   2> 3430 T1073 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f3c80e5 name:ZooKeeperConnection Watcher:127.0.0.1:52036/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3431 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3433 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3435 T1045 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3622 T1045 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3625 T1045 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52047
[junit4:junit4]   2> 3626 T1045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3627 T1045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454
[junit4:junit4]   2> 3627 T1045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/'
[junit4:junit4]   2> 3662 T1045 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3663 T1045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3664 T1045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454
[junit4:junit4]   2> 3664 T1045 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/solr.xml
[junit4:junit4]   2> 3665 T1045 oasc.CoreContainer.<init> New CoreContainer 2017921752
[junit4:junit4]   2> 3666 T1045 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/'
[junit4:junit4]   2> 3666 T1045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/'
[junit4:junit4]   2> 3689 T1045 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4]   2> 3690 T1045 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3691 T1045 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 3691 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3692 T1045 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3692 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3693 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3694 T1045 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3694 T1045 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3695 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4]   2> 3722 T1045 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3741 T1045 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:52036/solr
[junit4:junit4]   2> 3742 T1045 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 3743 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@34059959
[junit4:junit4]   2> 3744 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3745 T1083 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3745 T1083 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 3746 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52048
[junit4:junit4]   2> 3746 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52048
[junit4:junit4]   2> 3777 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40005 with negotiated timeout 20000 for client /140.211.11.196:52048
[junit4:junit4]   2> 3777 T1083 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40005, negotiated timeout = 20000
[junit4:junit4]   2> 3777 T1084 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34059959 name:ZooKeeperConnection Watcher:127.0.0.1:52036 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3778 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3780 T1050 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13bbae253e40005
[junit4:junit4]   2> 3834 T1084 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 3834 T1047 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:52048 which had sessionid 0x13bbae253e40005
[junit4:junit4]   2> 3834 T1045 oaz.ZooKeeper.close Session: 0x13bbae253e40005 closed
[junit4:junit4]   2> 3835 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4]   2> 3840 T1068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3841 T1068 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:52039_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52039"}
[junit4:junit4]   2> 3847 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@4e78ee73
[junit4:junit4]   2> 3848 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3849 T1085 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3849 T1085 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 3850 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52049
[junit4:junit4]   2> 3850 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52049
[junit4:junit4]   2> 3921 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40006 with negotiated timeout 20000 for client /140.211.11.196:52049
[junit4:junit4]   2> 3921 T1085 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40006, negotiated timeout = 20000
[junit4:junit4]   2> 3922 T1086 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e78ee73 name:ZooKeeperConnection Watcher:127.0.0.1:52036/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3922 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3924 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40006 type:create cxid:0x1 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4022 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40006 type:create cxid:0x2 zxid:0x4c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4091 T1067 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> 4091 T1073 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> 4091 T1045 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52047_
[junit4:junit4]   2> 4093 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40006 type:delete cxid:0x4 zxid:0x4f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:52047_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:52047_
[junit4:junit4]   2> 4156 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52047_
[junit4:junit4]   2> 4203 T1067 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4203 T1073 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4203 T1067 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> 4203 T1073 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> 4240 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4247 T1087 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/collection1
[junit4:junit4]   2> 4247 T1087 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4248 T1087 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4248 T1087 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4249 T1087 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/collection1/'
[junit4:junit4]   2> 4251 T1087 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4252 T1087 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/collection1/lib/README' to classloader
[junit4:junit4]   2> 4305 T1087 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 4377 T1087 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4478 T1087 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4485 T1087 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5112 T1087 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5124 T1087 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5128 T1087 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5140 T1087 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5144 T1087 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5148 T1087 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5149 T1087 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5150 T1087 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1356050096454/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1/
[junit4:junit4]   2> 5150 T1087 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40363068
[junit4:junit4]   2> 5151 T1087 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5152 T1087 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1 forceNew:false
[junit4:junit4]   2> 5152 T1087 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1
[junit4:junit4]   2> 5152 T1087 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1/index/
[junit4:junit4]   2> 5152 T1087 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5153 T1087 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1/index forceNew:false
[junit4:junit4]   2> 5155 T1087 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@669b6b8c lockFactory=org.apache.lucene.store.NativeFSLockFactory@3351f55)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5155 T1087 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5155 T1087 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1/index
[junit4:junit4]   2> 5156 T1087 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 5157 T1087 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5157 T1087 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 5158 T1087 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5158 T1087 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 5158 T1087 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5158 T1087 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5159 T1087 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5160 T1087 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5160 T1087 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5161 T1087 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 5161 T1087 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 5162 T1087 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5162 T1087 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 5162 T1087 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 5163 T1087 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 5163 T1087 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5164 T1087 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5164 T1087 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5165 T1087 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5166 T1087 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5166 T1087 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5167 T1087 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5167 T1087 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5168 T1087 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5169 T1087 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 5169 T1087 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 5174 T1087 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5177 T1087 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 5178 T1087 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> 5179 T1087 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1
[junit4:junit4]   2> 5180 T1087 oass.SolrIndexSearcher.<init> Opening Searcher@39aabfba main
[junit4:junit4]   2> 5181 T1087 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5181 T1087 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5181 T1087 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 5196 T1087 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 5254 T1088 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@39aabfba main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5257 T1087 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5257 T1087 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 5663 T1068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5664 T1068 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:52047_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52047"}
[junit4:junit4]   2> 5664 T1068 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 5664 T1068 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 5694 T1067 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> 5694 T1086 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> 5694 T1073 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> 6261 T1087 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 6261 T1087 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52047 collection:collection1 shard:shard1
[junit4:junit4]   2> 6262 T1087 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 6297 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40006 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> 6298 T1087 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6299 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40006 type:create cxid:0x44 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6308 T1087 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6308 T1087 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6308 T1087 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52047/collection1/
[junit4:junit4]   2> 6309 T1087 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6309 T1087 oasc.SyncStrategy.syncToMe http://127.0.0.1:52047/collection1/ has no replicas
[junit4:junit4]   2> 6309 T1087 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52047/collection1/
[junit4:junit4]   2> 6309 T1087 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 6315 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40006 type:create cxid:0x4e zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6708 T1068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6751 T1067 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> 6751 T1073 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> 6751 T1086 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> 6776 T1087 oasc.ZkController.register We are http://127.0.0.1:52047/collection1/ and leader is http://127.0.0.1:52047/collection1/
[junit4:junit4]   2> 6776 T1087 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52047
[junit4:junit4]   2> 6776 T1087 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6777 T1087 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 6777 T1087 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6779 T1087 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6780 T1045 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4]   2> 6781 T1045 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6782 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 6975 T1045 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 6979 T1045 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52051
[junit4:junit4]   2> 6980 T1045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6980 T1045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818
[junit4:junit4]   2> 6981 T1045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/'
[junit4:junit4]   2> 7025 T1045 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7026 T1045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7026 T1045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818
[junit4:junit4]   2> 7027 T1045 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/solr.xml
[junit4:junit4]   2> 7027 T1045 oasc.CoreContainer.<init> New CoreContainer 609039831
[junit4:junit4]   2> 7028 T1045 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/'
[junit4:junit4]   2> 7029 T1045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/'
[junit4:junit4]   2> 7057 T1045 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 30000
[junit4:junit4]   2> 7059 T1045 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7059 T1045 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 7060 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7060 T1045 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7061 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7062 T1045 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7062 T1045 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7063 T1045 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7063 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=30000&connTimeout=15000&retry=false
[junit4:junit4]   2> 7084 T1045 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7103 T1045 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:52036/solr
[junit4:junit4]   2> 7104 T1045 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 7105 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@3777cf76
[junit4:junit4]   2> 7106 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7107 T1098 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 7108 T1098 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 7108 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52052
[junit4:junit4]   2> 7108 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52052
[junit4:junit4]   2> 7110 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40007 with negotiated timeout 20000 for client /140.211.11.196:52052
[junit4:junit4]   2> 7110 T1098 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40007, negotiated timeout = 20000
[junit4:junit4]   2> 7111 T1099 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3777cf76 name:ZooKeeperConnection Watcher:127.0.0.1:52036 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7111 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7113 T1050 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13bbae253e40007
[junit4:junit4]   2> 7114 T1099 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 7114 T1047 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:52052 which had sessionid 0x13bbae253e40007
[junit4:junit4]   2> 7114 T1045 oaz.ZooKeeper.close Session: 0x13bbae253e40007 closed
[junit4:junit4]   2> 7115 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=15000&connTimeout=30000
[junit4:junit4]   2> 7125 T1045 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:52036/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2a114d6c
[junit4:junit4]   2> 7127 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7127 T1100 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:52036. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 7128 T1100 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:52036, initiating session
[junit4:junit4]   2> 7128 T1047 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:52053
[junit4:junit4]   2> 7129 T1047 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:52053
[junit4:junit4]   2> 7130 T1049 oazs.ZooKeeperServer.finishSessionInit Established session 0x13bbae253e40008 with negotiated timeout 20000 for client /140.211.11.196:52053
[junit4:junit4]   2> 7130 T1100 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:52036, sessionid = 0x13bbae253e40008, negotiated timeout = 20000
[junit4:junit4]   2> 7130 T1101 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a114d6c name:ZooKeeperConnection Watcher:127.0.0.1:52036/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7131 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7132 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7133 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7135 T1045 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52051_
[junit4:junit4]   2> 7136 T1050 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13bbae253e40008 type:delete cxid:0x4 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:52051_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:52051_
[junit4:junit4]   2> 7145 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52051_
[junit4:junit4]   2> 7155 T1086 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> 7155 T1067 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 7155 T1073 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 7155 T1067 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> 7156 T1073 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> 7157 T1086 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 7168 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7176 T1102 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/collection1
[junit4:junit4]   2> 7176 T1102 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7177 T1102 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7177 T1102 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7179 T1102 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/collection1/'
[junit4:junit4]   2> 7180 T1102 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7180 T1102 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/collection1/lib/README' to classloader
[junit4:junit4]   2> 7235 T1102 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 7276 T1068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7277 T1068 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:52047_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52047"}
[junit4:junit4]   2> 7292 T1067 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> 7292 T1101 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> 7292 T1073 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> 7292 T1086 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> 7315 T1102 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 7416 T1102 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 7424 T1102 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8117 T1102 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8128 T1102 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8131 T1102 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8143 T1102 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8147 T1102 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8151 T1102 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8152 T1102 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8153 T1102 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1356050099818/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/
[junit4:junit4]   2> 8153 T1102 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40363068
[junit4:junit4]   2> 8154 T1102 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 8154 T1102 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2 forceNew:false
[junit4:junit4]   2> 8155 T1102 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2
[junit4:junit4]   2> 8155 T1102 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/index/
[junit4:junit4]   2> 8155 T1102 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8156 T1102 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/index forceNew:false
[junit4:junit4]   2> 8158 T1102 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@7b61c4fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@26e1cc3f)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8158 T1102 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 8158 T1102 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/index
[junit4:junit4]   2> 8159 T1102 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8160 T1102 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8160 T1102 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8161 T1102 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8161 T1102 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8161 T1102 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8162 T1102 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8162 T1102 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8163 T1102 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8163 T1102 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8164 T1102 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8164 T1102 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8165 T1102 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8165 T1102 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8165 T1102 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8166 T1102 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8166 T1102 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8167 T1102 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8167 T1102 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8168 T1102 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8169 T1102 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8169 T1102 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8170 T1102 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8170 T1102 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8171 T1102 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8171 T1102 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8172 T1102 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8178 T1102 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8181 T1102 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8183 T1102 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> 8184 T1102 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2
[junit4:junit4]   2> 8185 T1102 oass.SolrIndexSearcher.<init> Opening Searcher@3bf2bb22 main
[junit4:junit4]   2> 8186 T1102 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8186 T1102 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8186 T1102 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8207 T1102 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8288 T1103 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3bf2bb22 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8297 T1102 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 8297 T1102 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8301 T1068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8301 T1068 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:52051_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52051"}
[junit4:junit4]   2> 8302 T1068 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 8302 T1068 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 8325 T1067 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> 8325 T1101 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> 8325 T1086 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> 8325 T1073 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> 9300 T1102 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 9300 T1102 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52051 collection:collection1 shard:shard1
[junit4:junit4]   2> 9307 T1102 oasc.ZkController.register We are http://127.0.0.1:52051/collection1/ and leader is http://127.0.0.1:52047/collection1/
[junit4:junit4]   2> 9308 T1102 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52051
[junit4:junit4]   2> 9308 T1102 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 9308 T1102 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C47 name=collection1 org.apache.solr.core.SolrCore@3c2b6aec url=http://127.0.0.1:52051/collection1 node=127.0.0.1:52051_ C47_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:52051_, base_url=http://127.0.0.1:52051}
[junit4:junit4]   2> 9309 T1104 C47 P52051 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 9309 T1102 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9311 T1104 C47 P52051 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 9311 T1104 C47 P52051 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 9311 T1104 C47 P52051 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 9311 T1045 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4]   2> 9312 T1045 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9312 T1045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9318 T1104 C47 P52051 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:52047/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 9318 T1104 C47 P52051 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:52051 START replicas=[http://127.0.0.1:52047/collection1/] nUpdates=100
[junit4:junit4]   2> 9319 T1104 C47 P52051 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 9319 T1104 C47 P52051 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 9319 T1104 C47 P52051 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 9320 T1104 C47 P52051 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9327 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9339 T1068 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C48 name=collection1 org.apache.solr.core.SolrCore@6187838f url=http://127.0.0.1:52047/collection1 node=127.0.0.1:52047_ C48_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52047_, base_url=http://127.0.0.1:52047, leader=true}
[junit4:junit4]   2> 9340 T1076 C48 P52047 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 9341 T1068 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:52051_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52051"}
[junit4:junit4]   2> ASYNC  NEW_CORE C49 name=collection1 org.apache.solr.core.SolrCore@d5d9e71 url=http://127.0.0.1:52039/collection1 node=127.0.0.1:52039_ C49_STATE=coll:control_collection core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:52039_, base_url=http://127.0.0.1:52039, leader=true}
[junit4:junit4]   2> 9344 T1057 C49 P52039 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/control/data
[junit4:junit4]   2> 9346 T1057 C49 P52039 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@3fa3342c lockFactory=org.apache.lucene.store.NativeFSLockFactory@479cfe1a)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9346 T1057 C49 P52039 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 9349 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[1 (1421921592134336513)]} 0 6
[junit4:junit4]   2> 9349 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10001 (1421921592134336512)]} 0 6
[junit4:junit4]   2> 9351 T1078 C48 P52047 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty1
[junit4:junit4]   2> 9353 T1078 C48 P52047 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@669b6b8c lockFactory=org.apache.lucene.store.NativeFSLockFactory@3351f55)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9353 T1078 C48 P52047 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 9359 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[1 (1421921592142725120)]} 0 8
[junit4:junit4]   2> 9359 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10001 (1421921592143773696)]} 0 7
[junit4:junit4]   2> 9363 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10002 (1421921592154259456)]} 0 1
[junit4:junit4]   2> 9363 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[2 (1421921592154259457)]} 0 1
[junit4:junit4]   2> 9366 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[2 (1421921592157405184)]} 0 1
[junit4:junit4]   2> 9366 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10002 (1421921592157405185)]} 0 1
[junit4:junit4]   2> 9367 T1067 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> 9367 T1086 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> 9367 T1101 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> 9367 T1073 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> 9369 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10003 (1421921592160550912)]} 0 1
[junit4:junit4]   2> 9369 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[3 (1421921592160550913)]} 0 1
[junit4:junit4]   2> 9378 T1091 C47 P52051 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2
[junit4:junit4]   2>  C47_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:52051_, base_url=http://127.0.0.1:52051}
[junit4:junit4]   2> 9380 T1091 C47 P52051 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@7b61c4fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@26e1cc3f)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9381 T1091 C47 P52051 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 9383 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 9383 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 9384 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10003 (1421921592163696640)]} 0 13
[junit4:junit4]   2> 9384 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[3 (1421921592164745216)]} 0 12
[junit4:junit4]   2> 9387 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10004 (1421921592179425280)]} 0 1
[junit4:junit4]   2> 9388 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[4 (1421921592180473856)]} 0 1
[junit4:junit4]   2> 9394 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9394 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9395 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10004 (1421921592183619584)]} 0 5
[junit4:junit4]   2> 9395 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[4 (1421921592184668160)]} 0 4
[junit4:junit4]   2> 9398 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10005 (1421921592190959616)]} 0 1
[junit4:junit4]   2> 9401 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[5 (1421921592192008192)]} 0 3
[junit4:junit4]   2> 9404 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9404 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10005 (1421921592194105344)]} 0 4
[junit4:junit4]   2> 9408 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10006 (1421921592201445376)]} 0 1
[junit4:junit4]   2> 9409 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9409 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[5 (1421921592198299648)]} 0 5
[junit4:junit4]   2> 9413 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[6 (1421921592206688256)]} 0 1
[junit4:junit4]   2> 9414 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9415 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10006 (1421921592205639680)]} 0 4
[junit4:junit4]   2> 9419 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9419 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10007 (1421921592212979712)]} 0 1
[junit4:junit4]   2> 9419 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[6 (1421921592209833984)]} 0 4
[junit4:junit4]   2> 9423 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[7 (1421921592217174016)]} 0 1
[junit4:junit4]   2> 9424 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9425 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10007 (1421921592216125440)]} 0 4
[junit4:junit4]   2> 9429 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10008 (1421921592223465472)]} 0 1
[junit4:junit4]   2> 9430 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 9430 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[7 (1421921592220319744)]} 0 5
[junit4:junit4]   2> 9434 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[8 (1421921592228708352)]} 0 1
[junit4:junit4]   2> 9435 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9435 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10008 (1421921592226611200)]} 0 4
[junit4:junit4]   2> 9438 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10004 (-1421921592233951232)]} 0 0
[junit4:junit4]   2> 9441 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9441 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[8 (1421921592232902656)]} 0 4
[junit4:junit4]   2> 9443 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9444 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10004 (-1421921592237096960)]} 0 3
[junit4:junit4]   2> 9444 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[4 (-1421921592240242688)]} 0 0
[junit4:junit4]   2> 9447 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10009 (1421921592242339840)]} 0 1
[junit4:junit4]   2> 9449 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9450 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[4 (-1421921592243388416)]} 0 3
[junit4:junit4]   2> 9454 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9454 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[9 (1421921592249679872)]} 0 1
[junit4:junit4]   2> 9454 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10009 (1421921592246534144)]} 0 4
[junit4:junit4]   2> 9458 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10010 (1421921592253874176)]} 0 1
[junit4:junit4]   2> 9460 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9461 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[9 (1421921592252825600)]} 0 5
[junit4:junit4]   2> 9464 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9465 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10010 (1421921592257019904)]} 0 5
[junit4:junit4]   2> 9466 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10 (1421921592260165632)]} 0 3
[junit4:junit4]   2> 9468 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10011 (1421921592264359936)]} 0 1
[junit4:junit4]   2> 9474 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9475 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10 (1421921592266457088)]} 0 6
[junit4:junit4]   2> 9475 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9476 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10011 (1421921592268554240)]} 0 5
[junit4:junit4]   2> 9478 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[11 (1421921592274845696)]} 0 1
[junit4:junit4]   2> 9480 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10012 (1421921592276942848)]} 0 1
[junit4:junit4]   2> 9485 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9486 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[11 (1421921592279040000)]} 0 5
[junit4:junit4]   2> 9487 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9488 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10012 (1421921592281137152)]} 0 5
[junit4:junit4]   2> 9490 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10007 (-1421921592288477184)]} 0 0
[junit4:junit4]   2> 9490 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[12 (1421921592287428608)]} 0 1
[junit4:junit4]   2> 9496 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9497 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10007 (-1421921592291622912)]} 0 4
[junit4:junit4]   2> 9499 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 9499 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[12 (1421921592292671488)]} 0 6
[junit4:junit4]   2> 9501 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10013 (1421921592298962944)]} 0 1
[junit4:junit4]   2> 9502 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[7 (-1421921592301060096)]} 0 0
[junit4:junit4]   2> 9508 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9508 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[7 (-1421921592304205824)]} 0 3
[junit4:junit4]   2> 9508 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9509 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10013 (1421921592303157248)]} 0 5
[junit4:junit4]   2> 9512 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[13 (1421921592310497280)]} 0 1
[junit4:junit4]   2> 9512 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10008 (-1421921592311545856)]} 0 0
[junit4:junit4]   2> 9518 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9519 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10008 (-1421921592314691584)]} 0 4
[junit4:junit4]   2> 9519 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9520 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[13 (1421921592314691585)]} 0 5
[junit4:junit4]   2> 9522 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10014 (1421921592320983040)]} 0 1
[junit4:junit4]   2> 9522 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[8 (-1421921592322031616)]} 0 0
[junit4:junit4]   2> 9527 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9528 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[8 (-1421921592325177345)]} 0 3
[junit4:junit4]   2> 9529 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9530 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10014 (1421921592325177344)]} 0 5
[junit4:junit4]   2> 9531 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[14 (1421921592330420224)]} 0 1
[junit4:junit4]   2> 9533 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10015 (1421921592332517376)]} 0 1
[junit4:junit4]   2> 9537 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9537 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[14 (1421921592333565952)]} 0 4
[junit4:junit4]   2> 9539 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9539 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10015 (1421921592335663104)]} 0 4
[junit4:junit4]   2> 9542 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[15 (1421921592340905984)]} 0 2
[junit4:junit4]   2> 9543 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10016 (1421921592343003136)]} 0 1
[junit4:junit4]   2> 9550 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9550 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9550 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10016 (1421921592347197440)]} 0 4
[junit4:junit4]   2> 9551 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[15 (1421921592346148864)]} 0 6
[junit4:junit4]   2> 9553 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10009 (-1421921592354537472)]} 0 0
[junit4:junit4]   2> 9554 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[16 (1421921592354537473)]} 0 1
[junit4:junit4]   2> 9558 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9559 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10009 (-1421921592357683200)]} 0 3
[junit4:junit4]   2> 9561 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9562 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10017 (1421921592362926080)]} 0 1
[junit4:junit4]   2> 9562 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[16 (1421921592358731776)]} 0 5
[junit4:junit4]   2> 9565 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[9 (-1421921592367120384)]} 0 0
[junit4:junit4]   2> 9568 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9568 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10017 (1421921592366071808)]} 0 4
[junit4:junit4]   2> 9570 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9571 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[9 (-1421921592370266112)]} 0 3
[junit4:junit4]   2> 9571 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10010 (-1421921592373411840)]} 0 0
[junit4:junit4]   2> 9575 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[17 (1421921592376557568)]} 0 1
[junit4:junit4]   2> 9576 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9577 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10010 (-1421921592376557568)]} 0 3
[junit4:junit4]   2> 9581 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10018 (1421921592382849024)]} 0 1
[junit4:junit4]   2> 9583 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 9584 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[17 (1421921592380751872)]} 0 6
[junit4:junit4]   2> 9587 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10 (-1421921592390189056)]} 0 0
[junit4:junit4]   2> 9588 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9589 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10018 (1421921592387043328)]} 0 5
[junit4:junit4]   2> 9592 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10013 (-1421921592395431936)]} 0 0
[junit4:junit4]   2> 9593 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9594 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10 (-1421921592393334784)]} 0 4
[junit4:junit4]   2> 9597 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9598 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[18 (1421921592400674816)]} 0 1
[junit4:junit4]   2> 9598 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10013 (-1421921592398577664)]} 0 3
[junit4:junit4]   2> 9602 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10019 (1421921592404869120)]} 0 1
[junit4:junit4]   2> 9605 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9605 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[18 (1421921592404869120)]} 0 4
[junit4:junit4]   2> 9608 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[13 (-1421921592412209152)]} 0 0
[junit4:junit4]   2> 9609 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9610 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10019 (1421921592409063424)]} 0 5
[junit4:junit4]   2> 9613 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9613 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10014 (-1421921592417452032)]} 0 0
[junit4:junit4]   2> 9614 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[13 (-1421921592415354880)]} 0 3
[junit4:junit4]   2> 9619 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[19 (1421921592422694912)]} 0 2
[junit4:junit4]   2> 9619 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9620 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10014 (-1421921592421646336)]} 0 3
[junit4:junit4]   2> 9624 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10020 (1421921592427937792)]} 0 1
[junit4:junit4]   2> 9626 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9627 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[19 (1421921592426889216)]} 0 5
[junit4:junit4]   2> 9631 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[14 (-1421921592435277824)]} 0 1
[junit4:junit4]   2> 9631 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9632 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10020 (1421921592432132096)]} 0 5
[junit4:junit4]   2> 9634 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10017 (-1421921592439472128)]} 0 0
[junit4:junit4]   2> 9637 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9638 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[14 (-1421921592439472128)]} 0 4
[junit4:junit4]   2> 9640 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9641 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10017 (-1421921592443666432)]} 0 3
[junit4:junit4]   2> 9644 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[20 (1421921592446812160)]} 0 3
[junit4:junit4]   2> 9645 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10021 (1421921592449957888)]} 0 1
[junit4:junit4]   2> 9654 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9654 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9655 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10021 (1421921592454152192)]} 0 7
[junit4:junit4]   2> 9655 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[20 (1421921592452055040)]} 0 9
[junit4:junit4]   2> 9659 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[17 (-1421921592465686528)]} 0 1
[junit4:junit4]   2> 9659 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10022 (1421921592465686529)]} 0 1
[junit4:junit4]   2> 9665 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9666 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9666 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[17 (-1421921592468832257)]} 0 4
[junit4:junit4]   2> 9666 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10022 (1421921592468832256)]} 0 4
[junit4:junit4]   2> 9669 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10018 (-1421921592476172288)]} 0 0
[junit4:junit4]   2> 9670 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[21 (1421921592476172289)]} 0 1
[junit4:junit4]   2> 9674 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9675 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10018 (-1421921592479318016)]} 0 3
[junit4:junit4]   2> 9678 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9679 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10023 (1421921592485609472)]} 0 1
[junit4:junit4]   2> 9680 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[21 (1421921592480366592)]} 0 7
[junit4:junit4]   2> 9683 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[22 (1421921592489803776)]} 0 1
[junit4:junit4]   2> 9688 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 9689 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10023 (1421921592489803776)]} 0 7
[junit4:junit4]   2> 9691 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9692 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10024 (1421921592499240960)]} 0 1
[junit4:junit4]   2> 9692 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[22 (1421921592493998080)]} 0 6
[junit4:junit4]   2> 9695 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[18 (-1421921592503435264)]} 0 0
[junit4:junit4]   2> 9699 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9700 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10024 (1421921592503435264)]} 0 5
[junit4:junit4]   2> 9701 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9702 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[18 (-1421921592506580992)]} 0 4
[junit4:junit4]   2> 9705 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10025 (1421921592511823872)]} 0 2
[junit4:junit4]   2> 9707 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[23 (1421921592514969600)]} 0 2
[junit4:junit4]   2> 9712 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9713 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10025 (1421921592518115328)]} 0 5
[junit4:junit4]   2> 9714 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9715 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[23 (1421921592519163904)]} 0 6
[junit4:junit4]   2> 9716 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10019 (-1421921592525455360)]} 0 0
[junit4:junit4]   2> 9719 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[24 (1421921592527552512)]} 0 1
[junit4:junit4]   2> 9722 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9723 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10019 (-1421921592528601088)]} 0 4
[junit4:junit4]   2> 9725 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9726 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[24 (1421921592530698240)]} 0 5
[junit4:junit4]   2> 9729 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10026 (1421921592535941120)]} 0 3
[junit4:junit4]   2> 9731 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[25 (1421921592540135424)]} 0 2
[junit4:junit4]   2> 9737 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9738 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9738 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10026 (1421921592541184000)]} 0 7
[junit4:junit4]   2> 9739 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[25 (1421921592544329728)]} 0 5
[junit4:junit4]   2> 9742 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10027 (1421921592551669760)]} 0 1
[junit4:junit4]   2> 9742 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[19 (-1421921592552718336)]} 0 0
[junit4:junit4]   2> 9747 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9748 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[19 (-1421921592555864064)]} 0 3
[junit4:junit4]   2> 9749 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9750 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10027 (1421921592555864065)]} 0 5
[junit4:junit4]   2> 9752 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[26 (1421921592562155520)]} 0 1
[junit4:junit4]   2> 9754 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10028 (1421921592564252672)]} 0 1
[junit4:junit4]   2> 9759 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9760 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[26 (1421921592566349824)]} 0 5
[junit4:junit4]   2> 9762 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 9763 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10028 (1421921592568446976)]} 0 6
[junit4:junit4]   2> 9764 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[27 (1421921592574738432)]} 0 1
[junit4:junit4]   2> 9767 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10020 (-1421921592577884160)]} 0 1
[junit4:junit4]   2> 9771 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9772 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[27 (1421921592578932736)]} 0 5
[junit4:junit4]   2> 9772 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9773 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10020 (-1421921592582078464)]} 0 3
[junit4:junit4]   2> 9776 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[28 (1421921592587321344)]} 0 1
[junit4:junit4]   2> 9777 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10029 (1421921592588369920)]} 0 1
[junit4:junit4]   2> 9785 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 9785 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9786 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[28 (1421921592592564224)]} 0 6
[junit4:junit4]   2> 9786 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10029 (1421921592592564225)]} 0 6
[junit4:junit4]   2> 9790 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[20 (-1421921592602001408)]} 0 1
[junit4:junit4]   2> 9790 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10021 (-1421921592602001409)]} 0 1
[junit4:junit4]   2> 9794 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9795 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[20 (-1421921592605147136)]} 0 3
[junit4:junit4]   2> 9797 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9798 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10021 (-1421921592606195712)]} 0 5
[junit4:junit4]   2> 9800 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[29 (1421921592612487168)]} 0 2
[junit4:junit4]   2> 9802 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10030 (1421921592614584320)]} 0 1
[junit4:junit4]   2> 9807 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9808 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[29 (1421921592616681472)]} 0 5
[junit4:junit4]   2> 9809 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9810 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10030 (1421921592618778624)]} 0 5
[junit4:junit4]   2> 9813 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[21 (-1421921592626118656)]} 0 1
[junit4:junit4]   2> 9817 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10031 (1421921592627167232)]} 0 4
[junit4:junit4]   2> 9818 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9819 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[21 (-1421921592629264384)]} 0 4
[junit4:junit4]   2> 9824 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[30 (1421921592636604416)]} 0 2
[junit4:junit4]   2> 9826 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9827 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10031 (1421921592634507264)]} 0 7
[junit4:junit4]   2> 9831 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10032 (1421921592644993024)]} 0 1
[junit4:junit4]   2> 9832 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9833 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[30 (1421921592641847296)]} 0 6
[junit4:junit4]   2> 9837 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[31 (1421921592651284480)]} 0 1
[junit4:junit4]   2> 9840 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9841 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10032 (1421921592651284480)]} 0 6
[junit4:junit4]   2> 9844 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9845 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[31 (1421921592655478784)]} 0 5
[junit4:junit4]   2> 9845 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10024 (-1421921592659673088)]} 0 1
[junit4:junit4]   2> 9848 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[32 (1421921592662818816)]} 0 1
[junit4:junit4]   2> 9852 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9853 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10024 (-1421921592663867392)]} 0 5
[junit4:junit4]   2> 9856 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10033 (1421921592671207424)]} 0 1
[junit4:junit4]   2> 9858 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 9858 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[32 (1421921592668061696)]} 0 6
[junit4:junit4]   2> 9862 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[24 (-1421921592677498880)]} 0 1
[junit4:junit4]   2> 9864 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9865 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10033 (1421921592676450304)]} 0 5
[junit4:junit4]   2> 9867 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9868 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[24 (-1421921592681693184)]} 0 3
[junit4:junit4]   2> 9869 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10034 (1421921592684838912)]} 0 1
[junit4:junit4]   2> 9873 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[33 (1421921592687984640)]} 0 1
[junit4:junit4]   2> 9876 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9877 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10034 (1421921592689033216)]} 0 5
[junit4:junit4]   2> 9879 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9880 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[33 (1421921592692178944)]} 0 5
[junit4:junit4]   2> 9880 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10026 (-1421921592697421824)]} 0 0
[junit4:junit4]   2> 9884 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[34 (1421921592700567552)]} 0 1
[junit4:junit4]   2> 9886 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9888 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10026 (-1421921592700567552)]} 0 5
[junit4:junit4]   2> 9892 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10035 (1421921592708956160)]} 0 1
[junit4:junit4]   2> 9892 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9893 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[34 (1421921592704761856)]} 0 6
[junit4:junit4]   2> 9896 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[26 (-1421921592714199040)]} 0 0
[junit4:junit4]   2> 9899 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9901 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10035 (1421921592713150464)]} 0 6
[junit4:junit4]   2> 9902 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9903 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[26 (-1421921592717344768)]} 0 4
[junit4:junit4]   2> 9903 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10029 (-1421921592721539072)]} 0 0
[junit4:junit4]   2> 9910 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9910 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[35 (1421921592724684800)]} 0 4
[junit4:junit4]   2> 9910 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10029 (-1421921592724684800)]} 0 4
[junit4:junit4]   2> 9915 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10036 (1421921592733073408)]} 0 2
[junit4:junit4]   2> 9919 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9920 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[35 (1421921592733073408)]} 0 7
[junit4:junit4]   2> 9923 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[29 (-1421921592742510592)]} 0 0
[junit4:junit4]   2> 9923 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9924 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10036 (1421921592738316288)]} 0 6
[junit4:junit4]   2> 9927 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10031 (-1421921592746704896)]} 0 0
[junit4:junit4]   2> 9929 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9930 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[29 (-1421921592745656320)]} 0 4
[junit4:junit4]   2> 9933 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[36 (1421921592751947776)]} 0 1
[junit4:junit4]   2> 9934 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9935 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10031 (-1421921592749850624)]} 0 5
[junit4:junit4]   2> 9939 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10037 (1421921592758239232)]} 0 1
[junit4:junit4]   2> 9940 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9941 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[36 (1421921592756142080)]} 0 5
[junit4:junit4]   2> 9943 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[31 (-1421921592763482112)]} 0 0
[junit4:junit4]   2> 9946 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9947 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10037 (1421921592762433536)]} 0 4
[junit4:junit4]   2> 9948 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 9949 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[31 (-1421921592766627840)]} 0 3
[junit4:junit4]   2> 9950 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10038 (1421921592769773568)]} 0 1
[junit4:junit4]   2> 9953 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[37 (1421921592772919296)]} 0 1
[junit4:junit4]   2> 9957 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 9958 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10038 (1421921592772919296)]} 0 6
[junit4:junit4]   2> 9960 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9961 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[37 (1421921592777113600)]} 0 5
[junit4:junit4]   2> 9962 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10039 (1421921592782356480)]} 0 1
[junit4:junit4]   2> 9965 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[38 (1421921592785502208)]} 0 1
[junit4:junit4]   2> 9969 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9970 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10039 (1421921592786550784)]} 0 5
[junit4:junit4]   2> 9972 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9973 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[38 (1421921592789696512)]} 0 5
[junit4:junit4]   2> 9973 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10040 (1421921592793890816)]} 0 1
[junit4:junit4]   2> 9976 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[39 (1421921592797036544)]} 0 1
[junit4:junit4]   2> 9980 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9981 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10040 (1421921592798085120)]} 0 5
[junit4:junit4]   2> 9983 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9984 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[39 (1421921592801230848)]} 0 5
[junit4:junit4]   2> 9987 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10041 (1421921592805425152)]} 0 4
[junit4:junit4]   2> 9988 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[40 (1421921592809619456)]} 0 1
[junit4:junit4]   2> 9995 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9995 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 9996 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10041 (1421921592811716608)]} 0 7
[junit4:junit4]   2> 9996 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[40 (1421921592813813760)]} 0 5
[junit4:junit4]   2> 9998 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10033 (-1421921592821153792)]} 0 0
[junit4:junit4]   2> 10000 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[41 (1421921592822202368)]} 0 1
[junit4:junit4]   2> 10003 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10004 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10033 (-1421921592824299520)]} 0 3
[junit4:junit4]   2> 10007 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10007 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[41 (1421921592826396672)]} 0 4
[junit4:junit4]   2> 10008 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10042 (1421921592830590976)]} 0 1
[junit4:junit4]   2> 10010 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[33 (-1421921592833736704)]} 0 0
[junit4:junit4]   2> 10015 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10016 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10042 (1421921592834785280)]} 0 5
[junit4:junit4]   2> 10016 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10017 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[33 (-1421921592836882432)]} 0 4
[junit4:junit4]   2> 10020 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10043 (1421921592843173888)]} 0 1
[junit4:junit4]   2> 10021 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[42 (1421921592844222464)]} 0 1
[junit4:junit4]   2> 10028 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10029 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 10029 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10043 (1421921592847368193)]} 0 6
[junit4:junit4]   2> 10030 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[42 (1421921592847368192)]} 0 7
[junit4:junit4]   2> 10032 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10037 (-1421921592856805376)]} 0 0
[junit4:junit4]   2> 10033 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[43 (1421921592856805377)]} 0 1
[junit4:junit4]   2> 10038 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10039 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10037 (-1421921592860999680)]} 0 4
[junit4:junit4]   2> 10041 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10041 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[43 (1421921592862048256)]} 0 5
[junit4:junit4]   2> 10043 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10044 (1421921592867291136)]} 0 1
[junit4:junit4]   2> 10044 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[37 (-1421921592869388288)]} 0 0
[junit4:junit4]   2> 10049 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10050 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10051 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10044 (1421921592871485440)]} 0 5
[junit4:junit4]   2> 10053 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[37 (-1421921592872534016)]} 0 6
[junit4:junit4]   2> 10055 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10045 (1421921592879874048)]} 0 1
[junit4:junit4]   2> 10057 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[44 (1421921592881971200)]} 0 1
[junit4:junit4]   2> 10062 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10063 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10045 (1421921592884068352)]} 0 5
[junit4:junit4]   2> 10064 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10064 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[44 (1421921592886165504)]} 0 4
[junit4:junit4]   2> 10068 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[45 (1421921592893505536)]} 0 1
[junit4:junit4]   2> 10070 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10046 (1421921592892456960)]} 0 4
[junit4:junit4]   2> 10077 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10078 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10046 (1421921592899796992)]} 0 5
[junit4:junit4]   2> 10079 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10079 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[45 (1421921592897699840)]} 0 8
[junit4:junit4]   2> 10081 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10042 (-1421921592907137024)]} 0 0
[junit4:junit4]   2> 10083 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[46 (1421921592909234176)]} 0 1
[junit4:junit4]   2> 10088 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10089 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10042 (-1421921592911331328)]} 0 5
[junit4:junit4]   2> 10090 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10090 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[46 (1421921592913428480)]} 0 4
[junit4:junit4]   2> 10093 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10047 (1421921592919719936)]} 0 1
[junit4:junit4]   2> 10095 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[42 (-1421921592921817088)]} 0 1
[junit4:junit4]   2> 10101 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10102 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10047 (1421921592924962816)]} 0 6
[junit4:junit4]   2> 10102 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10103 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[42 (-1421921592926011392)]} 0 5
[junit4:junit4]   2> 10107 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10048 (1421921592933351424)]} 0 2
[junit4:junit4]   2> 10107 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[47 (1421921592934400000)]} 0 1
[junit4:junit4]   2> 10115 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10116 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 10116 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10048 (1421921592938594305)]} 0 6
[junit4:junit4]   2> 10116 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[47 (1421921592938594304)]} 0 6
[junit4:junit4]   2> 10120 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10049 (1421921592948031488)]} 0 1
[junit4:junit4]   2> 10121 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[48 (1421921592949080064)]} 0 2
[junit4:junit4]   2> 10127 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10128 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10128 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10049 (1421921592952225792)]} 0 5
[junit4:junit4]   2> 10129 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[48 (1421921592953274368)]} 0 5
[junit4:junit4]   2> 10132 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[49 (1421921592960614400)]} 0 1
[junit4:junit4]   2> 10133 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10050 (1421921592960614401)]} 0 2
[junit4:junit4]   2> 10139 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10139 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[49 (1421921592964808704)]} 0 4
[junit4:junit4]   2> 10140 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10141 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10050 (1421921592965857280)]} 0 5
[junit4:junit4]   2> 10144 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10051 (1421921592973197313)]} 0 1
[junit4:junit4]   2> 10146 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[50 (1421921592973197312)]} 0 4
[junit4:junit4]   2> 10152 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10153 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10153 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10051 (1421921592977391616)]} 0 6
[junit4:junit4]   2> 10154 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[50 (1421921592979488768)]} 0 5
[junit4:junit4]   2> 10157 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10044 (-1421921592986828801)]} 0 1
[junit4:junit4]   2> 10157 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[51 (1421921592986828800)]} 0 1
[junit4:junit4]   2> 10164 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10164 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10165 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10044 (-1421921592991023105)]} 0 5
[junit4:junit4]   2> 10165 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[51 (1421921592991023104)]} 0 5
[junit4:junit4]   2> 10168 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10052 (1421921592998363136)]} 0 1
[junit4:junit4]   2> 10169 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[44 (-1421921592999411712)]} 0 1
[junit4:junit4]   2> 10175 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10175 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10176 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10052 (1421921593002557440)]} 0 5
[junit4:junit4]   2> 10176 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[44 (-1421921593003606016)]} 0 4
[junit4:junit4]   2> 10180 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10053 (1421921593010946048)]} 0 1
[junit4:junit4]   2> 10180 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[52 (1421921593010946049)]} 0 1
[junit4:junit4]   2> 10188 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 10188 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 10189 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[52 (1421921593015140352)]} 0 6
[junit4:junit4]   2> 10189 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10053 (1421921593015140353)]} 0 6
[junit4:junit4]   2> 10193 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10054 (1421921593024577536)]} 0 1
[junit4:junit4]   2> 10193 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[53 (1421921593024577537)]} 0 1
[junit4:junit4]   2> 10200 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10200 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10200 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[53 (1421921593028771841)]} 0 4
[junit4:junit4]   2> 10201 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10054 (1421921593028771840)]} 0 5
[junit4:junit4]   2> 10205 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[54 (1421921593037160448)]} 0 1
[junit4:junit4]   2> 10205 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10055 (1421921593037160449)]} 0 1
[junit4:junit4]   2> 10212 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10212 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10213 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10055 (1421921593041354752)]} 0 5
[junit4:junit4]   2> 10213 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[54 (1421921593041354753)]} 0 5
[junit4:junit4]   2> 10215 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10047 (-1421921593048694784)]} 0 0
[junit4:junit4]   2> 10218 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[55 (1421921593049743360)]} 0 2
[junit4:junit4]   2> 10221 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10222 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10047 (-1421921593051840512)]} 0 4
[junit4:junit4]   2> 10226 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10227 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10056 (1421921593059180544)]} 0 2
[junit4:junit4]   2> 10227 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[55 (1421921593054986240)]} 0 6
[junit4:junit4]   2> 10230 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[47 (-1421921593064423424)]} 0 0
[junit4:junit4]   2> 10235 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10236 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10056 (1421921593064423424)]} 0 6
[junit4:junit4]   2> 10238 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10050 (-1421921593072812032)]} 0 0
[junit4:junit4]   2> 10240 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10241 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[47 (-1421921593071763456)]} 0 4
[junit4:junit4]   2> 10245 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10245 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[56 (1421921593079103488)]} 0 1
[junit4:junit4]   2> 10246 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10050 (-1421921593075957760)]} 0 5
[junit4:junit4]   2> 10252 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10253 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[56 (1421921593083297792)]} 0 5
[junit4:junit4]   2> 10258 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10057 (1421921593083297792)]} 0 10
[junit4:junit4]   2> 10258 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[50 (-1421921593091686400)]} 0 2
[junit4:junit4]   2> 10264 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10265 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10265 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[50 (-1421921593096929281)]} 0 4
[junit4:junit4]   2> 10266 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10057 (1421921593096929280)]} 0 5
[junit4:junit4]   2> 10268 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10055 (-1421921593104269312)]} 0 0
[junit4:junit4]   2> 10269 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[57 (1421921593104269313)]} 0 1
[junit4:junit4]   2> 10273 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10274 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10055 (-1421921593107415040)]} 0 3
[junit4:junit4]   2> 10277 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 10278 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10058 (1421921593113706496)]} 0 1
[junit4:junit4]   2> 10278 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[57 (1421921593108463616)]} 0 6
[junit4:junit4]   2> 10281 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[55 (-1421921593117900800)]} 0 0
[junit4:junit4]   2> 10284 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10285 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10058 (1421921593116852224)]} 0 5
[junit4:junit4]   2> 10286 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10287 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[55 (-1421921593121046528)]} 0 3
[junit4:junit4]   2> 10287 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10056 (-1421921593124192256)]} 0 0
[junit4:junit4]   2> 10291 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[58 (1421921593127337984)]} 0 1
[junit4:junit4]   2> 10292 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10293 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10056 (-1421921593127337984)]} 0 3
[junit4:junit4]   2> 10297 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10059 (1421921593133629440)]} 0 1
[junit4:junit4]   2> 10297 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10298 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[58 (1421921593130483712)]} 0 5
[junit4:junit4]   2> 10300 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[56 (-1421921593137823744)]} 0 0
[junit4:junit4]   2> 10303 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10303 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10059 (1421921593136775168)]} 0 4
[junit4:junit4]   2> 10305 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10306 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[56 (-1421921593140969472)]} 0 3
[junit4:junit4]   2> 10307 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10060 (1421921593144115200)]} 0 1
[junit4:junit4]   2> 10310 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[59 (1421921593147260928)]} 0 1
[junit4:junit4]   2> 10314 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10315 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10060 (1421921593148309504)]} 0 5
[junit4:junit4]   2> 10317 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10318 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[59 (1421921593151455232)]} 0 5
[junit4:junit4]   2> 10320 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10061 (1421921593155649536)]} 0 3
[junit4:junit4]   2> 10322 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[60 (1421921593159843840)]} 0 1
[junit4:junit4]   2> 10328 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10328 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10061 (1421921593160892416)]} 0 6
[junit4:junit4]   2> 10330 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10330 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[60 (1421921593164038144)]} 0 5
[junit4:junit4]   2> 10331 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10058 (-1421921593170329600)]} 0 0
[junit4:junit4]   2> 10334 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[61 (1421921593172426752)]} 0 1
[junit4:junit4]   2> 10336 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10337 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10058 (-1421921593173475328)]} 0 3
[junit4:junit4]   2> 10341 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10062 (1421921593179766784)]} 0 1
[junit4:junit4]   2> 10341 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10342 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[61 (1421921593176621056)]} 0 5
[junit4:junit4]   2> 10344 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[58 (-1421921593183961088)]} 0 0
[junit4:junit4]   2> 10348 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10348 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10062 (1421921593183961088)]} 0 4
[junit4:junit4]   2> 10349 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10350 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[58 (-1421921593187106816)]} 0 3
[junit4:junit4]   2> 10351 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10060 (-1421921593191301120)]} 0 0
[junit4:junit4]   2> 10354 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[62 (1421921593193398272)]} 0 1
[junit4:junit4]   2> 10356 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10357 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10060 (-1421921593194446848)]} 0 3
[junit4:junit4]   2> 10361 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10063 (1421921593200738304)]} 0 1
[junit4:junit4]   2> 10361 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 10362 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[62 (1421921593196544000)]} 0 6
[junit4:junit4]   2> 10365 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[60 (-1421921593205981184)]} 0 0
[junit4:junit4]   2> 10368 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10369 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10063 (1421921593204932608)]} 0 5
[junit4:junit4]   2> 10371 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10372 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10061 (-1421921593213321216)]} 0 1
[junit4:junit4]   2> 10372 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[60 (-1421921593209126912)]} 0 4
[junit4:junit4]   2> 10376 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[63 (1421921593216466944)]} 0 1
[junit4:junit4]   2> 10377 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10378 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10061 (-1421921593216466944)]} 0 3
[junit4:junit4]   2> 10382 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10064 (1421921593222758400)]} 0 1
[junit4:junit4]   2> 10383 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10383 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[63 (1421921593220661248)]} 0 4
[junit4:junit4]   2> 10386 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[61 (-1421921593228001280)]} 0 0
[junit4:junit4]   2> 10387 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10387 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10064 (1421921593224855552)]} 0 4
[junit4:junit4]   2> 10391 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10065 (1421921593232195584)]} 0 1
[junit4:junit4]   2> 10391 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10392 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[61 (-1421921593231147008)]} 0 3
[junit4:junit4]   2> 10396 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[64 (1421921593237438464)]} 0 1
[junit4:junit4]   2> 10398 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10398 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10065 (1421921593236389888)]} 0 4
[junit4:junit4]   2> 10402 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10402 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[64 (1421921593240584192)]} 0 4
[junit4:junit4]   2> 10404 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10066 (1421921593243729920)]} 0 3
[junit4:junit4]   2> 10406 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[65 (1421921593247924224)]} 0 1
[junit4:junit4]   2> 10411 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10412 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10066 (1421921593248972800)]} 0 6
[junit4:junit4]   2> 10413 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10413 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[65 (1421921593252118528)]} 0 4
[junit4:junit4]   2> 10415 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10067 (1421921593257361408)]} 0 1
[junit4:junit4]   2> 10417 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[66 (1421921593259458560)]} 0 1
[junit4:junit4]   2> 10422 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10422 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10067 (1421921593261555712)]} 0 4
[junit4:junit4]   2> 10423 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10424 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[66 (1421921593262604288)]} 0 5
[junit4:junit4]   2> 10425 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10063 (-1421921593268895744)]} 0 0
[junit4:junit4]   2> 10427 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[67 (1421921593269944320)]} 0 1
[junit4:junit4]   2> 10431 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10432 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10063 (-1421921593272041472)]} 0 4
[junit4:junit4]   2> 10435 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 10436 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10068 (1421921593279381504)]} 0 1
[junit4:junit4]   2> 10436 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[67 (1421921593274138624)]} 0 6
[junit4:junit4]   2> 10439 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[63 (-1421921593283575808)]} 0 0
[junit4:junit4]   2> 10443 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10444 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10068 (1421921593283575808)]} 0 5
[junit4:junit4]   2> 10444 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10445 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[63 (-1421921593286721536)]} 0 3
[junit4:junit4]   2> 10448 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10069 (1421921593291964416)]} 0 1
[junit4:junit4]   2> 10449 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[68 (1421921593293012992)]} 0 1
[junit4:junit4]   2> 10455 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10456 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10069 (1421921593296158720)]} 0 5
[junit4:junit4]   2> 10456 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10457 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[68 (1421921593297207296)]} 0 5
[junit4:junit4]   2> 10460 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10070 (1421921593304547328)]} 0 1
[junit4:junit4]   2> 10461 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[69 (1421921593305595904)]} 0 1
[junit4:junit4]   2> 10467 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10467 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10070 (1421921593308741632)]} 0 4
[junit4:junit4]   2> 10468 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10469 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[69 (1421921593309790208)]} 0 5
[junit4:junit4]   2> 10472 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[70 (1421921593317130240)]} 0 1
[junit4:junit4]   2> 10473 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10071 (1421921593316081664)]} 0 3
[junit4:junit4]   2> 10480 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10480 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10481 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[70 (1421921593321324544)]} 0 6
[junit4:junit4]   2> 10481 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10071 (1421921593322373120)]} 0 5
[junit4:junit4]   2> 10484 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[71 (1421921593329713152)]} 0 1
[junit4:junit4]   2> 10485 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10072 (1421921593330761728)]} 0 1
[junit4:junit4]   2> 10491 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10492 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10072 (1421921593333907456)]} 0 5
[junit4:junit4]   2> 10492 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10493 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[71 (1421921593333907457)]} 0 6
[junit4:junit4]   2> 10494 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[10068 (-1421921593341247488)]} 0 0
[junit4:junit4]   2> 10497 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[72 (1421921593343344640)]} 0 1
[junit4:junit4]   2> 10500 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10501 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[10068 (-1421921593344393216)]} 0 4
[junit4:junit4]   2> 10511 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[10073 (1421921593351733248)]} 0 7
[junit4:junit4]   2> 10511 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 10512 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[72 (1421921593347538944)]} 0 12
[junit4:junit4]   2> 10515 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[68 (-1421921593363267584)]} 0 0
[junit4:junit4]   2> 10519 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10520 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10073 (1421921593363267584)]} 0 6
[junit4:junit4]   2> 10520 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10521 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[68 (-1421921593366413312)]} 0 3
[junit4:junit4]   2> 10523 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10069 (-1421921593371656192)]} 0 0
[junit4:junit4]   2> 10525 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[73 (1421921593372704768)]} 0 1
[junit4:junit4]   2> 10528 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10529 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10069 (-1421921593374801920)]} 0 3
[junit4:junit4]   2> 10531 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10531 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[73 (1421921593375850496)]} 0 4
[junit4:junit4]   2> 10533 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10074 (1421921593381093376)]} 0 1
[junit4:junit4]   2> 10534 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[69 (-1421921593383190528)]} 0 0
[junit4:junit4]   2> 10539 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10539 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10539 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10074 (1421921593384239104)]} 0 4
[junit4:junit4]   2> 10540 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[69 (-1421921593386336256)]} 0 3
[junit4:junit4]   2> 10542 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10072 (-1421921593391579136)]} 0 0
[junit4:junit4]   2> 10544 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[74 (1421921593392627712)]} 0 1
[junit4:junit4]   2> 10547 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10548 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10072 (-1421921593394724864)]} 0 3
[junit4:junit4]   2> 10550 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10550 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[74 (1421921593395773440)]} 0 4
[junit4:junit4]   2> 10552 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10075 (1421921593401016320)]} 0 1
[junit4:junit4]   2> 10553 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[72 (-1421921593403113472)]} 0 0
[junit4:junit4]   2> 10558 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10558 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10559 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[72 (-1421921593406259200)]} 0 3
[junit4:junit4]   2> 10559 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10075 (1421921593404162048)]} 0 5
[junit4:junit4]   2> 10564 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[75 (1421921593412550657)]} 0 2
[junit4:junit4]   2> 10565 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10076 (1421921593412550656)]} 0 3
[junit4:junit4]   2> 10572 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10573 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10573 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[75 (1421921593416744960)]} 0 7
[junit4:junit4]   2> 10573 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10076 (1421921593418842112)]} 0 5
[junit4:junit4]   2> 10576 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10076 (-1421921593427230721)]} 0 0
[junit4:junit4]   2> 10577 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[76 (1421921593427230720)]} 0 1
[junit4:junit4]   2> 10582 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10583 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10076 (-1421921593430376448)]} 0 4
[junit4:junit4]   2> 10584 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10584 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[76 (1421921593431425024)]} 0 4
[junit4:junit4]   2> 10587 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10077 (1421921593437716480)]} 0 1
[junit4:junit4]   2> 10587 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[76 (-1421921593438765056)]} 0 0
[junit4:junit4]   2> 10593 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10593 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10593 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10077 (1421921593440862208)]} 0 4
[junit4:junit4]   2> 10595 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[76 (-1421921593441910784)]} 0 5
[junit4:junit4]   2> 10596 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10077 (-1421921593448202240)]} 0 0
[junit4:junit4]   2> 10598 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[77 (1421921593449250816)]} 0 1
[junit4:junit4]   2> 10601 T1091 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 10602 T1078 C48 P52047 /update {wt=javabin&version=2} {delete=[10077 (-1421921593451347968)]} 0 3
[junit4:junit4]   2> 10606 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10078 (1421921593457639424)]} 0 1
[junit4:junit4]   2> 10607 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 10608 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[77 (1421921593453445120)]} 0 7
[junit4:junit4]   2> 10611 T1057 C49 P52039 /update {wt=javabin&version=2} {delete=[77 (-1421921593463930880)]} 0 0
[junit4:junit4]   2> 10613 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10614 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10078 (1421921593461833728)]} 0 5
[junit4:junit4]   2> 10618 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10618 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10079 (1421921593470222336)]} 0 1
[junit4:junit4]   2> 10618 T1079 C48 P52047 /update {wt=javabin&version=2} {delete=[77 (-1421921593467076608)]} 0 4
[junit4:junit4]   2> 10622 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[78 (1421921593474416640)]} 0 1
[junit4:junit4]   2> 10625 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10626 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10079 (1421921593474416640)]} 0 5
[junit4:junit4]   2> 10629 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10630 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10080 (1421921593482805248)]} 0 1
[junit4:junit4]   2> 10630 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[78 (1421921593478610944)]} 0 5
[junit4:junit4]   2> 10634 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[79 (1421921593486999552)]} 0 1
[junit4:junit4]   2> 10637 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10638 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[10080 (1421921593486999552)]} 0 5
[junit4:junit4]   2> 10641 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10642 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[79 (1421921593491193856)]} 0 5
[junit4:junit4]   2> 10642 T1057 C49 P52039 /update {wt=javabin&version=2} {add=[10081 (1421921593494339584)]} 0 2
[junit4:junit4]   2> 10647 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[80 (1421921593500631040)]} 0 2
[junit4:junit4]   2> 10650 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10651 T1079 C48 P52047 /update {wt=javabin&version=2} {add=[10081 (1421921593499582464)]} 0 6
[junit4:junit4]   2> 10654 T1058 C49 P52039 /update {wt=javabin&version=2} {delete=[10081 (-1421921593509019648)]} 0 0
[junit4:junit4]   2> 10655 T1092 C47 P52051 REQ /update {distrib.from=http://127.0.0.1:52047/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10656 T1078 C48 P52047 /update {wt=javabin&version=2} {add=[80 (1421921593504825344)]} 0 6
[junit4:junit4]   2> 10659 T1058 C49 P52039 /update {wt=javabin&version=2} {add=[81 (1421921593513213952)]} 0 1
[junit4:junit4]   2> 10660 T1092 C47 P52051 REQ /update {dist

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

4809 T1168 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 64809 T1168 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 64810 T1168 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 64810 T1168 C50 P52051 oasu.TransactionLog.forceClose SEVERE Error: Forcing close of tlog{file=./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/tlog/tlog.0000000000000000003 refcount=1}
[junit4:junit4]   2> 64813 T1168 C50 P52051 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/index.20121221023522425
[junit4:junit4]   2> 64813 T1168 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 64814 T1168 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/index.20121221023522425
[junit4:junit4]   2> 64814 T1168 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/index.20121221023522425
[junit4:junit4]   2> 64814 T1168 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2/index.20121221023522425
[junit4:junit4]   2> 65067 T1044 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4]   2> 65295 T1168 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2
[junit4:junit4]   2> 65295 T1168 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1356050093023/jetty2
[junit4:junit4]   2> 65295 T1168 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> 65296 T1168 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 65296 T1168 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 65296 T1168 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=SimpleText, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=fr_CA, timezone=ART
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=92975424,total=442630144
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SortByFunctionTest, SpellPossibilityIteratorTest, FieldAnalysisRequestHandlerTest, DateFieldTest, JSONWriterTest, IndexBasedSpellCheckerTest, TestPerFieldSimilarity, TestSuggestSpellingConverter, NoCacheHeaderTest, TestRTGBase, TestIBSimilarityFactory, LeaderElectionIntegrationTest, MBeansHandlerTest, SearchHandlerTest, TestQuerySenderNoQuery, SolrCoreCheckLockOnStartupTest, TestNumberUtils, CacheHeaderTest, TermVectorComponentDistributedTest, SolrRequestParserTest, TestLMJelinekMercerSimilarityFactory, TestJoin, ResponseLogComponentTest, TestAnalyzedSuggestions, BinaryUpdateRequestHandlerTest, SuggesterWFSTTest, TestDocumentBuilder, DefaultValueUpdateProcessorTest, TestLFUCache, CoreAdminHandlerTest, SimplePostToolTest, WordBreakSolrSpellCheckerTest, SpellCheckCollatorTest, BasicDistributedZk2Test, TestStressRecovery, JsonLoaderTest, PluginInfoTest, TestDefaultSimilarityFactory, CircularListTest, CSVRequestHandlerTest, TestGroupingSearch, SOLR749Test, FastVectorHighlighterTest, ShardRoutingCustomTest, DirectUpdateHandlerOptimizeTest, TestXIncludeConfig, TestIndexingPerformance, HighlighterConfigTest, SuggesterFSTTest, SolrCmdDistributorTest, PreAnalyzedFieldTest, DateMathParserTest, SpatialFilterTest, SolrPluginUtilsTest, MinimalSchemaTest, BadComponentTest, ZkControllerTest, AlternateDirectoryTest, RecoveryZkTest]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RecoveryZkTest -Dtests.seed=A685A2C3C44081CA -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr_CA -Dtests.timezone=ART -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR   0.00s J0 | RecoveryZkTest (suite) <<<
[junit4:junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=1170, name=coreLoadExecutor-528-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([A685A2C3C44081CA]:0)
[junit4:junit4]    > 	at java.lang.Thread.getStackTrace(Thread.java:1495)
[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:977)
[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:267)
[junit4:junit4]    > 	at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:223)
[junit4:junit4]    > 	at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:239)
[junit4:junit4]    > 	at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:444)
[junit4:junit4]    > 	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:713)
[junit4:junit4]    > 	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:602)
[junit4:junit4]    > 	at org.apache.solr.core.CoreContainer.createFromZk(CoreContainer.java:947)
[junit4:junit4]    > 	at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1029)
[junit4:junit4]    > 	at org.apache.solr.core.CoreContainer$3.call(CoreContainer.java:627)
[junit4:junit4]    > 	at org.apache.solr.core.CoreContainer$3.call(CoreContainer.java:622)
[junit4:junit4]    > 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]    > 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]    > 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4]    > 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]    > 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]    > 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
[junit4:junit4]    > 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:679)
[junit4:junit4]    > Caused by: java.lang.AssertionError: Directory not closed: BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1f54e65e lockFactory=org.apache.lucene.store.NativeFSLockFactory@31d137a8)
[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]    > 	... 1 more
[junit4:junit4] Completed on J0 in 65.49s, 1 test, 1 error <<< FAILURES!

[...truncated 381 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:353: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:178: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:438: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1175: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:840: There were test failures: 244 suites, 1011 tests, 1 suite-level error, 21 ignored (3 assumptions)

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



Mime
View raw message