You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/02/26 23:15:11 UTC

[JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 192 - Failure

Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/192/

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=532, name=coreLoadExecutor-118-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=532, name=coreLoadExecutor-118-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
	at __randomizedtesting.SeedInfo.seed([561ABA8D077A85ED]: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:520)
	at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:980)
	at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:878)
	at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:870)
	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:244)
	at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:458)
	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:730)
	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:619)
	at org.apache.solr.core.CoreContainer.createFromZk(CoreContainer.java:967)
	at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1049)
	at org.apache.solr.core.CoreContainer$3.call(CoreContainer.java:634)
	at org.apache.solr.core.CoreContainer$3.call(CoreContainer.java:629)
	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@2745240a lockFactory=org.apache.lucene.store.NativeFSLockFactory@67c78f98)
	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 8364 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4]   2> 0 T451 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 57 T451 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-RecoveryZkTest-1361915463392
[junit4:junit4]   2> 61 T451 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 62 T452 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 81 T452 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 81 T452 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 81 T452 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 82 T452 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 85 T452 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 163 T451 oasc.ZkTestServer.run start zk server on port:32506
[junit4:junit4]   2> 164 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@70ca8f43
[junit4:junit4]   2> 165 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 166 T457 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 167 T457 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 168 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32507
[junit4:junit4]   2> 168 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32507
[junit4:junit4]   2> 169 T455 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 175 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0000 with negotiated timeout 10000 for client /140.211.11.196:32507
[junit4:junit4]   2> 175 T457 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0000, negotiated timeout = 10000
[junit4:junit4]   2> 176 T458 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70ca8f43 name:ZooKeeperConnection Watcher:127.0.0.1:32506 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 176 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 177 T451 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 185 T456 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d187cc6fe0000
[junit4:junit4]   2> 186 T458 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 186 T451 oaz.ZooKeeper.close Session: 0x13d187cc6fe0000 closed
[junit4:junit4]   2> 187 T453 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:32507 which had sessionid 0x13d187cc6fe0000
[junit4:junit4]   2> 188 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@72a5ce92
[junit4:junit4]   2> 190 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 190 T459 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 191 T459 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 192 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32508
[junit4:junit4]   2> 192 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32508
[junit4:junit4]   2> 197 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0001 with negotiated timeout 10000 for client /140.211.11.196:32508
[junit4:junit4]   2> 197 T459 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0001, negotiated timeout = 10000
[junit4:junit4]   2> 198 T460 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72a5ce92 name:ZooKeeperConnection Watcher:127.0.0.1:32506/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 198 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 199 T451 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 208 T451 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 214 T451 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 223 T451 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 231 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 434 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 453 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 459 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 472 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 474 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 488 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 489 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 501 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 502 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 514 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 515 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 522 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 523 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 535 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 537 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 548 T451 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 550 T451 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 558 T456 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d187cc6fe0001
[junit4:junit4]   2> 559 T460 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 559 T453 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d187cc6fe0001, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:679)
[junit4:junit4]   2> 
[junit4:junit4]   2> 559 T451 oaz.ZooKeeper.close Session: 0x13d187cc6fe0001 closed
[junit4:junit4]   2> 560 T453 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:32508 which had sessionid 0x13d187cc6fe0001
[junit4:junit4]   2> 3142 T451 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3514 T451 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32516
[junit4:junit4]   2> 3566 T451 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3620 T451 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3621 T451 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893
[junit4:junit4]   2> 3645 T451 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893/solr.xml
[junit4:junit4]   2> 3648 T451 oasc.CoreContainer.<init> New CoreContainer 1064301273
[junit4:junit4]   2> 3649 T451 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893/'
[junit4:junit4]   2> 3650 T451 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893/'
[junit4:junit4]   2> 4989 T451 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 4990 T451 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4990 T451 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4991 T451 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4991 T451 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4992 T451 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4993 T451 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4993 T451 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4994 T451 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 5043 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 5548 T451 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 5582 T451 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:32506/solr
[junit4:junit4]   2> 5659 T451 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 5659 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5b489c06
[junit4:junit4]   2> 5661 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 5662 T471 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 5663 T471 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 5663 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32538
[junit4:junit4]   2> 5664 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32538
[junit4:junit4]   2> 5665 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0002 with negotiated timeout 20000 for client /140.211.11.196:32538
[junit4:junit4]   2> 5665 T471 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0002, negotiated timeout = 20000
[junit4:junit4]   2> 5666 T472 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b489c06 name:ZooKeeperConnection Watcher:127.0.0.1:32506 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5666 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 5667 T456 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d187cc6fe0002
[junit4:junit4]   2> 5668 T472 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 5668 T453 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:32538 which had sessionid 0x13d187cc6fe0002
[junit4:junit4]   2> 5668 T451 oaz.ZooKeeper.close Session: 0x13d187cc6fe0002 closed
[junit4:junit4]   2> 5673 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 5686 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@7ef72e77
[junit4:junit4]   2> 5687 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 5687 T473 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 5688 T473 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 5688 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32539
[junit4:junit4]   2> 5688 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32539
[junit4:junit4]   2> 5689 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0003 with negotiated timeout 20000 for client /140.211.11.196:32539
[junit4:junit4]   2> 5689 T473 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0003, negotiated timeout = 20000
[junit4:junit4]   2> 5690 T474 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ef72e77 name:ZooKeeperConnection Watcher:127.0.0.1:32506/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5690 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 5692 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5693 T451 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 5696 T451 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32516_
[junit4:junit4]   2> 5697 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:32516_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:32516_
[junit4:junit4]   2> 5698 T451 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32516_
[junit4:junit4]   2> 5708 T451 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 5722 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:delete cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 5732 T451 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 5734 T451 oasc.Overseer.start Overseer (id=89254491810824195-127.0.0.1:32516_-n_0000000000) starting
[junit4:junit4]   2> 5735 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5736 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5737 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5738 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5740 T476 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 5740 T451 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 5752 T451 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5753 T475 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 5864 T477 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893/collection1
[junit4:junit4]   2> 5865 T477 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 5866 T477 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5866 T477 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 5868 T477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893/collection1/'
[junit4:junit4]   2> 5869 T477 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5870 T477 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893/collection1/lib/README' to classloader
[junit4:junit4]   2> 5983 T477 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 6148 T477 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 6176 T477 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 6239 T477 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 7757 T477 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 7779 T477 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 7783 T477 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8265 T477 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8276 T477 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8281 T477 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8286 T477 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8367 T477 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1361915463893/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data/
[junit4:junit4]   2> 8373 T477 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14718242
[junit4:junit4]   2> 8387 T477 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 8458 T477 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data forceNew:false
[junit4:junit4]   2> 8458 T477 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data
[junit4:junit4]   2> 8459 T477 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data/index/
[junit4:junit4]   2> 8459 T477 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8494 T477 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data/index forceNew:false
[junit4:junit4]   2> 8755 T477 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22cf38a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@64a06824),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8755 T477 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 8757 T477 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data/index
[junit4:junit4]   2> 9447 T477 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9447 T477 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9526 T477 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9558 T477 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9572 T477 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9573 T477 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9575 T477 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9597 T477 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9601 T477 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9701 T477 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9725 T477 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data
[junit4:junit4]   2> 9768 T477 oass.SolrIndexSearcher.<init> Opening Searcher@1a779dce main
[junit4:junit4]   2> 9815 T477 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data/tlog
[junit4:junit4]   2> 9834 T477 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9834 T477 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9962 T478 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1a779dce main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9966 T477 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 9966 T477 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 9967 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 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> 10261 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10261 T475 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[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:32516_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32516"}
[junit4:junit4]   2> 10262 T475 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 10262 T475 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 10262 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 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> 10280 T474 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> 11013 T477 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11013 T477 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32516 collection:control_collection shard:shard1
[junit4:junit4]   2> 11026 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4]   2> 11048 T477 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 11093 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:delete cxid:0x78 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> 11094 T477 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 11094 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:create cxid:0x79 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11169 T477 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 11170 T477 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 11170 T477 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32516/collection1/
[junit4:junit4]   2> 11170 T477 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 11171 T477 oasc.SyncStrategy.syncToMe http://127.0.0.1:32516/collection1/ has no replicas
[junit4:junit4]   2> 11171 T477 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32516/collection1/
[junit4:junit4]   2> 11171 T477 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 11176 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0003 type:create cxid:0x83 zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11790 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11832 T474 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> 11848 T477 oasc.ZkController.register We are http://127.0.0.1:32516/collection1/ and leader is http://127.0.0.1:32516/collection1/
[junit4:junit4]   2> 11852 T477 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32516
[junit4:junit4]   2> 11852 T477 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 11852 T477 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 11853 T477 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11855 T477 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11860 T451 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 11861 T451 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 11932 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11956 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 11962 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@51f3eab7
[junit4:junit4]   2> 11963 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 11963 T479 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 11964 T479 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 11964 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32542
[junit4:junit4]   2> 11965 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32542
[junit4:junit4]   2> 11967 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0004 with negotiated timeout 10000 for client /140.211.11.196:32542
[junit4:junit4]   2> 11967 T479 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0004, negotiated timeout = 10000
[junit4:junit4]   2> 11968 T480 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51f3eab7 name:ZooKeeperConnection Watcher:127.0.0.1:32506/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 11968 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 11969 T451 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 11973 T451 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 12143 T451 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 12146 T451 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32543
[junit4:junit4]   2> 12147 T451 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12148 T451 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12149 T451 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306
[junit4:junit4]   2> 12149 T451 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306/solr.xml
[junit4:junit4]   2> 12150 T451 oasc.CoreContainer.<init> New CoreContainer 866219815
[junit4:junit4]   2> 12150 T451 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306/'
[junit4:junit4]   2> 12151 T451 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306/'
[junit4:junit4]   2> 12201 T451 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 12202 T451 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12202 T451 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 12203 T451 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12203 T451 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12204 T451 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12204 T451 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12205 T451 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12205 T451 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12206 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 12231 T451 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12254 T451 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:32506/solr
[junit4:junit4]   2> 12255 T451 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 12256 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@33d063fd
[junit4:junit4]   2> 12257 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12258 T490 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 12259 T490 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 12259 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32544
[junit4:junit4]   2> 12260 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32544
[junit4:junit4]   2> 12262 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0005 with negotiated timeout 20000 for client /140.211.11.196:32544
[junit4:junit4]   2> 12262 T490 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0005, negotiated timeout = 20000
[junit4:junit4]   2> 12262 T491 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33d063fd name:ZooKeeperConnection Watcher:127.0.0.1:32506 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12263 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12264 T456 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d187cc6fe0005
[junit4:junit4]   2> 12274 T491 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12274 T453 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:32544 which had sessionid 0x13d187cc6fe0005
[junit4:junit4]   2> 12274 T451 oaz.ZooKeeper.close Session: 0x13d187cc6fe0005 closed
[junit4:junit4]   2> 12275 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 12287 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5c3f1224
[junit4:junit4]   2> 12288 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12289 T492 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 12289 T492 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 12290 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32545
[junit4:junit4]   2> 12290 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32545
[junit4:junit4]   2> 12292 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0006 with negotiated timeout 20000 for client /140.211.11.196:32545
[junit4:junit4]   2> 12292 T492 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0006, negotiated timeout = 20000
[junit4:junit4]   2> 12292 T493 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c3f1224 name:ZooKeeperConnection Watcher:127.0.0.1:32506/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12292 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12293 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12295 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12303 T451 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 13306 T451 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32543_
[junit4:junit4]   2> 13307 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:32543_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:32543_
[junit4:junit4]   2> 13309 T451 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32543_
[junit4:junit4]   2> 13312 T480 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 13312 T493 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 13312 T474 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 13313 T474 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> 13327 T494 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306/collection1
[junit4:junit4]   2> 13327 T494 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 13328 T494 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 13328 T494 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 13330 T494 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306/collection1/'
[junit4:junit4]   2> 13331 T494 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306/collection1/lib/README' to classloader
[junit4:junit4]   2> 13332 T494 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 13346 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13347 T475 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[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:32516_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32516"}
[junit4:junit4]   2> 13358 T493 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> 13358 T474 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> 13358 T480 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> 13396 T494 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 13475 T494 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 13477 T494 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 13538 T494 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14176 T494 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14188 T494 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14191 T494 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14213 T494 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14217 T494 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14222 T494 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14224 T494 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14226 T494 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1361915475306/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1/
[junit4:junit4]   2> 14227 T494 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14718242
[junit4:junit4]   2> 14229 T494 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14230 T494 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1 forceNew:false
[junit4:junit4]   2> 14230 T494 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1
[junit4:junit4]   2> 14230 T494 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1/index/
[junit4:junit4]   2> 14231 T494 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14231 T494 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1/index forceNew:false
[junit4:junit4]   2> 14234 T494 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7228c7a1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@35389244),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14234 T494 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14234 T494 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1/index
[junit4:junit4]   2> 14237 T494 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14237 T494 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14238 T494 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14239 T494 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14241 T494 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14241 T494 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14241 T494 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14242 T494 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14243 T494 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14248 T494 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14253 T494 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1
[junit4:junit4]   2> 14253 T494 oass.SolrIndexSearcher.<init> Opening Searcher@1c4a1bda main
[junit4:junit4]   2> 14254 T494 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1/tlog
[junit4:junit4]   2> 14254 T494 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14255 T494 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14267 T495 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c4a1bda main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14272 T494 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 14273 T494 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 14863 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14864 T475 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[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:32543_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32543"}
[junit4:junit4]   2> 14864 T475 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 14865 T475 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 14884 T493 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> 14884 T480 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> 14884 T474 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> 15275 T494 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 15275 T494 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32543 collection:collection1 shard:shard1
[junit4:junit4]   2> 15276 T494 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 15294 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0006 type:delete cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 15295 T494 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 15295 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 15305 T494 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 15305 T494 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 15306 T494 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32543/collection1/
[junit4:junit4]   2> 15306 T494 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 15307 T494 oasc.SyncStrategy.syncToMe http://127.0.0.1:32543/collection1/ has no replicas
[junit4:junit4]   2> 15307 T494 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32543/collection1/
[junit4:junit4]   2> 15307 T494 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 15312 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16388 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16409 T480 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> 16409 T474 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> 16409 T493 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> 16436 T494 oasc.ZkController.register We are http://127.0.0.1:32543/collection1/ and leader is http://127.0.0.1:32543/collection1/
[junit4:junit4]   2> 16436 T494 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32543
[junit4:junit4]   2> 16436 T494 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 16437 T494 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 16437 T494 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16439 T494 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16440 T451 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 16440 T451 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 16441 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16623 T451 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 16626 T451 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32549
[junit4:junit4]   2> 16627 T451 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 16627 T451 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 16628 T451 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789
[junit4:junit4]   2> 16628 T451 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789/solr.xml
[junit4:junit4]   2> 16629 T451 oasc.CoreContainer.<init> New CoreContainer 1142506670
[junit4:junit4]   2> 16629 T451 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789/'
[junit4:junit4]   2> 16630 T451 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789/'
[junit4:junit4]   2> 16679 T451 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 16680 T451 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 16680 T451 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 16681 T451 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 16681 T451 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 16682 T451 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 16682 T451 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 16683 T451 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 16683 T451 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 16684 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 16705 T451 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 16730 T451 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:32506/solr
[junit4:junit4]   2> 16731 T451 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 16731 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@2d205042
[junit4:junit4]   2> 16733 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16733 T505 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 16734 T505 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 16734 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32550
[junit4:junit4]   2> 16735 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32550
[junit4:junit4]   2> 16737 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0007 with negotiated timeout 20000 for client /140.211.11.196:32550
[junit4:junit4]   2> 16737 T505 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0007, negotiated timeout = 20000
[junit4:junit4]   2> 16738 T506 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d205042 name:ZooKeeperConnection Watcher:127.0.0.1:32506 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16738 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16739 T456 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d187cc6fe0007
[junit4:junit4]   2> 16753 T506 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 16753 T451 oaz.ZooKeeper.close Session: 0x13d187cc6fe0007 closed
[junit4:junit4]   2> 16753 T453 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:32550 which had sessionid 0x13d187cc6fe0007
[junit4:junit4]   2> 16753 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 16764 T451 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:32506/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@377e9134
[junit4:junit4]   2> 16765 T451 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16766 T507 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:32506. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 16766 T507 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:32506, initiating session
[junit4:junit4]   2> 16767 T453 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32551
[junit4:junit4]   2> 16767 T453 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32551
[junit4:junit4]   2> 16768 T455 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d187cc6fe0008 with negotiated timeout 20000 for client /140.211.11.196:32551
[junit4:junit4]   2> 16769 T507 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:32506, sessionid = 0x13d187cc6fe0008, negotiated timeout = 20000
[junit4:junit4]   2> 16769 T508 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@377e9134 name:ZooKeeperConnection Watcher:127.0.0.1:32506/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16769 T451 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16770 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16772 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16779 T451 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 17782 T451 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32549_
[junit4:junit4]   2> 17783 T456 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d187cc6fe0008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:32549_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:32549_
[junit4:junit4]   2> 17784 T451 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32549_
[junit4:junit4]   2> 17788 T508 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 17788 T493 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 17788 T480 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 17788 T474 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 17789 T480 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> 17789 T474 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> 17789 T493 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> 17806 T509 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789/collection1
[junit4:junit4]   2> 17807 T509 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 17808 T509 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 17808 T509 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 17809 T509 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789/collection1/'
[junit4:junit4]   2> 17811 T509 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 17812 T509 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789/collection1/lib/README' to classloader
[junit4:junit4]   2> 17871 T509 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 17921 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17922 T475 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[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:32543_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32543"}
[junit4:junit4]   2> 17935 T508 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> 17935 T493 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> 17935 T480 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> 17935 T474 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> 17943 T509 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 17944 T509 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 18000 T509 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 18628 T509 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 18639 T509 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 18642 T509 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 18662 T509 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 18667 T509 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 18672 T509 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 18674 T509 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 18676 T509 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1361915479789/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/
[junit4:junit4]   2> 18676 T509 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14718242
[junit4:junit4]   2> 18677 T509 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 18677 T509 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2 forceNew:false
[junit4:junit4]   2> 18678 T509 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2
[junit4:junit4]   2> 18678 T509 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/index/
[junit4:junit4]   2> 18678 T509 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 18679 T509 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/index forceNew:false
[junit4:junit4]   2> 18681 T509 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5d5cd49f lockFactory=org.apache.lucene.store.NativeFSLockFactory@25c20c74),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 18681 T509 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 18682 T509 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/index
[junit4:junit4]   2> 18684 T509 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 18684 T509 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 18685 T509 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 18686 T509 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 18687 T509 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 18688 T509 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 18688 T509 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 18689 T509 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 18690 T509 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 18694 T509 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 18698 T509 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2
[junit4:junit4]   2> 18699 T509 oass.SolrIndexSearcher.<init> Opening Searcher@486f8860 main
[junit4:junit4]   2> 18699 T509 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/tlog
[junit4:junit4]   2> 18700 T509 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 18700 T509 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 18712 T510 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@486f8860 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 18719 T509 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 18720 T509 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19441 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19442 T475 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[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:32549_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32549"}
[junit4:junit4]   2> 19443 T475 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 19443 T475 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 19452 T508 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> 19452 T474 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> 19452 T480 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> 19452 T493 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> 19722 T509 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 19722 T509 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32549 collection:collection1 shard:shard1
[junit4:junit4]   2> 19725 T509 oasc.ZkController.register We are http://127.0.0.1:32549/collection1/ and leader is http://127.0.0.1:32543/collection1/
[junit4:junit4]   2> 19726 T509 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32549
[junit4:junit4]   2> 19726 T509 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 19726 T509 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> 19733 T509 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19734 T451 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 19735 T451 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 19735 T451 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@4183aedf url=http://127.0.0.1:32549/collection1 node=127.0.0.1:32549_ C0_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:32549_, base_url=http://127.0.0.1:32549}
[junit4:junit4]   2> 19745 T511 C0 P32549 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 19750 T511 C0 P32549 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 19750 T511 C0 P32549 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 19750 T511 C0 P32549 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19752 T511 C0 P32549 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19752 T451 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20967 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20968 T475 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[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:32549_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32549"}
[junit4:junit4]   2> 20987 T493 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> 20987 T508 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> 20987 T480 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> 20987 T474 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> 21757 T451 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 32549
[junit4:junit4]   2> 21761 T451 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1142506670
[junit4:junit4]   2> ASYNC  NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@757dbeaf url=http://127.0.0.1:32516/collection1 node=127.0.0.1:32516_ C1_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:32516_, base_url=http://127.0.0.1:32516, leader=true}
[junit4:junit4]   2> 21789 T465 C1 P32516 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/control/data
[junit4:junit4]   2> 21799 T465 C1 P32516 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22cf38a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@64a06824),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 21801 T465 C1 P32516 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22100 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10001 (1428071891726237696)]} 0 865
[junit4:junit4]   2> 22100 T465 C1 P32516 /update {wt=javabin&version=2} {add=[1 (1428071891726237697)]} 0 865
[junit4:junit4]   2> ASYNC  NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@e026161 url=http://127.0.0.1:32543/collection1 node=127.0.0.1:32543_ C2_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:32543_, base_url=http://127.0.0.1:32543, leader=true}
[junit4:junit4]   2> 22150 T484 C2 P32543 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty1
[junit4:junit4]   2> 22155 T484 C2 P32543 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7228c7a1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@35389244),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22156 T484 C2 P32543 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2>  C0_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:32549_, base_url=http://127.0.0.1:32549}
[junit4:junit4]   2> 22205 T499 C0 P32549 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2
[junit4:junit4]   2> 22210 T499 C0 P32549 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5d5cd49f lockFactory=org.apache.lucene.store.NativeFSLockFactory@25c20c74),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22211 T499 C0 P32549 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22224 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10001 (1428071892105822208)]} 0 18
[junit4:junit4]   2> 22226 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1428071892105822209)]} 0 24
[junit4:junit4]   2> 22227 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10001 (1428071892105822208)]} 0 85
[junit4:junit4]   2> 22227 T484 C2 P32543 /update {wt=javabin&version=2} {add=[1 (1428071892105822209)]} 0 85
[junit4:junit4]   2> 22234 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[1 (-1428071892192854016)]} 0 2
[junit4:junit4]   2> 22234 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10001 (-1428071892192854017)]} 0 2
[junit4:junit4]   2> 22249 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[1 (-1428071892199145473)]} 0 0
[junit4:junit4]   2> 22250 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10001 (-1428071892199145472)]} 0 1
[junit4:junit4]   2> 22251 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[1 (-1428071892199145473)]} 0 12
[junit4:junit4]   2> 22252 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10001 (-1428071892199145472)]} 0 13
[junit4:junit4]   2> 22260 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10002 (1428071892218019841)]} 0 3
[junit4:junit4]   2> 22260 T465 C1 P32516 /update {wt=javabin&version=2} {add=[2 (1428071892218019840)]} 0 3
[junit4:junit4]   2> 22273 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1428071892225359872)]} 0 3
[junit4:junit4]   2> 22274 T485 C2 P32543 /update {wt=javabin&version=2} {add=[2 (1428071892225359872)]} 0 10
[junit4:junit4]   2> 22275 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10002 (1428071892225359873)]} 0 3
[junit4:junit4]   2> 22275 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10002 (1428071892225359873)]} 0 11
[junit4:junit4]   2> 22280 T465 C1 P32516 /update {wt=javabin&version=2} {add=[3 (1428071892240039936)]} 0 2
[junit4:junit4]   2> 22282 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10003 (1428071892242137088)]} 0 2
[junit4:junit4]   2> 22294 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1428071892247379968)]} 0 3
[junit4:junit4]   2> 22295 T484 C2 P32543 /update {wt=javabin&version=2} {add=[3 (1428071892247379968)]} 0 10
[junit4:junit4]   2> 22296 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10003 (1428071892249477120)]} 0 2
[junit4:junit4]   2> 22297 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10003 (1428071892249477120)]} 0 10
[junit4:junit4]   2> 22299 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[2 (-1428071892262060032)]} 0 1
[junit4:junit4]   2> 22301 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10002 (-1428071892263108608)]} 0 1
[junit4:junit4]   2> 22307 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[2 (-1428071892267302912)]} 0 0
[junit4:junit4]   2> 22308 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[2 (-1428071892267302912)]} 0 5
[junit4:junit4]   2> 22308 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10002 (-1428071892268351488)]} 0 0
[junit4:junit4]   2> 22309 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10002 (-1428071892268351488)]} 0 5
[junit4:junit4]   2> 22314 T465 C1 P32516 /update {wt=javabin&version=2} {add=[4 (1428071892275691520)]} 0 3
[junit4:junit4]   2> 22315 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10004 (1428071892276740096)]} 0 3
[junit4:junit4]   2> 22325 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1428071892281982976)]} 0 2
[junit4:junit4]   2> 22326 T484 C2 P32543 /update {wt=javabin&version=2} {add=[4 (1428071892281982976)]} 0 9
[junit4:junit4]   2> 22328 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10004 (1428071892283031552)]} 0 2
[junit4:junit4]   2> 22329 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10004 (1428071892283031552)]} 0 11
[junit4:junit4]   2> 22332 T464 C1 P32516 /update {wt=javabin&version=2} {add=[5 (1428071892294565888)]} 0 3
[junit4:junit4]   2> 22335 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10005 (1428071892297711616)]} 0 3
[junit4:junit4]   2> 22343 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1428071892300857344)]} 0 2
[junit4:junit4]   2> 22344 T485 C2 P32543 /update {wt=javabin&version=2} {add=[5 (1428071892300857344)]} 0 9
[junit4:junit4]   2> 22347 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10005 (1428071892304003072)]} 0 2
[junit4:junit4]   2> 22348 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10005 (1428071892304003072)]} 0 10
[junit4:junit4]   2> 22350 T465 C1 P32516 /update {wt=javabin&version=2} {add=[6 (1428071892313440256)]} 0 3
[junit4:junit4]   2> 22354 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10006 (1428071892317634560)]} 0 3
[junit4:junit4]   2> 22362 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1428071892319731712)]} 0 2
[junit4:junit4]   2> 22363 T484 C2 P32543 /update {wt=javabin&version=2} {add=[6 (1428071892319731712)]} 0 9
[junit4:junit4]   2> 22365 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10006 (1428071892323926016)]} 0 2
[junit4:junit4]   2> 22366 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10006 (1428071892323926016)]} 0 9
[junit4:junit4]   2> 22369 T464 C1 P32516 /update {wt=javabin&version=2} {add=[7 (1428071892333363200)]} 0 3
[junit4:junit4]   2> 22372 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10007 (1428071892336508928)]} 0 3
[junit4:junit4]   2> 22381 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1428071892339654656)]} 0 3
[junit4:junit4]   2> 22382 T485 C2 P32543 /update {wt=javabin&version=2} {add=[7 (1428071892339654656)]} 0 10
[junit4:junit4]   2> 22384 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10007 (1428071892342800384)]} 0 2
[junit4:junit4]   2> 22385 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10007 (1428071892342800384)]} 0 9
[junit4:junit4]   2> 22388 T465 C1 P32516 /update {wt=javabin&version=2} {add=[8 (1428071892353286144)]} 0 3
[junit4:junit4]   2> 22391 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10008 (1428071892356431872)]} 0 3
[junit4:junit4]   2> 22400 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1428071892359577600)]} 0 2
[junit4:junit4]   2> 22401 T484 C2 P32543 /update {wt=javabin&version=2} {add=[8 (1428071892359577600)]} 0 10
[junit4:junit4]   2> 22404 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10008 (1428071892363771904)]} 0 2
[junit4:junit4]   2> 22405 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10008 (1428071892363771904)]} 0 10
[junit4:junit4]   2> 22408 T464 C1 P32516 /update {wt=javabin&version=2} {add=[9 (1428071892374257664)]} 0 3
[junit4:junit4]   2> 22412 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10009 (1428071892378451968)]} 0 2
[junit4:junit4]   2> 22421 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1428071892380549120)]} 0 3
[junit4:junit4]   2> 22422 T485 C2 P32543 /update {wt=javabin&version=2} {add=[9 (1428071892380549120)]} 0 11
[junit4:junit4]   2> 22425 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10009 (1428071892385792000)]} 0 2
[junit4:junit4]   2> 22426 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10009 (1428071892385792000)]} 0 9
[junit4:junit4]   2> 22428 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10 (1428071892395229184)]} 0 3
[junit4:junit4]   2> 22433 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10010 (1428071892400472064)]} 0 3
[junit4:junit4]   2> 22440 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1428071892401520640)]} 0 2
[junit4:junit4]   2> 22441 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10 (1428071892401520640)]} 0 10
[junit4:junit4]   2> 22444 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10010 (1428071892406763520)]} 0 2
[junit4:junit4]   2> 22445 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10010 (1428071892406763520)]} 0 9
[junit4:junit4]   2> 22448 T464 C1 P32516 /update {wt=javabin&version=2} {add=[11 (1428071892416200704)]} 0 3
[junit4:junit4]   2> 22451 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10011 (1428071892419346432)]} 0 3
[junit4:junit4]   2> 22460 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1428071892422492160)]} 0 2
[junit4:junit4]   2> 22462 T485 C2 P32543 /update {wt=javabin&version=2} {add=[11 (1428071892422492160)]} 0 10
[junit4:junit4]   2> 22465 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10011 (1428071892426686464)]} 0 4
[junit4:junit4]   2> 22465 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10011 (1428071892426686464)]} 0 10
[junit4:junit4]   2> 22467 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[11 (-1428071892437172224)]} 0 1
[junit4:junit4]   2> 22470 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10011 (-1428071892441366528)]} 0 1
[junit4:junit4]   2> 22476 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[11 (-1428071892442415104)]} 0 1
[junit4:junit4]   2> 22476 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[11 (-1428071892442415104)]} 0 5
[junit4:junit4]   2> 22477 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10011 (-1428071892445560832)]} 0 0
[junit4:junit4]   2> 22478 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10011 (-1428071892445560832)]} 0 5
[junit4:junit4]   2> 22483 T464 C1 P32516 /update {wt=javabin&version=2} {add=[12 (1428071892452900864)]} 0 3
[junit4:junit4]   2> 22484 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10012 (1428071892453949440)]} 0 3
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> ###### getShardId(1) in {}
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> ###### getShardId(1) in {}
[junit4:junit4]   1> ###### getShardId(1) in {control_collection=DocCollection(control_collection)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"1":{
[junit4:junit4]   1>           "state":"down",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"control_collection",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32516_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32516"}}}},
[junit4:junit4]   1>   "router":"compositeId"}}
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> ###### getShardId(2) in {control_collection=DocCollection(control_collection)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"1":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"control_collection",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32516_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32516",
[junit4:junit4]   1>           "leader":"true"}}}},
[junit4:junit4]   1>   "router":"compositeId"}}
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> ###### getShardId(2) in {control_collection=DocCollection(control_collection)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"1":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"control_collection",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32516_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32516",
[junit4:junit4]   1>           "leader":"true"}}}},
[junit4:junit4]   1>   "router":"compositeId"}}
[junit4:junit4]   1> ###### getShardId(2) in {collection1=DocCollection(collection1)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"2":{
[junit4:junit4]   1>           "state":"down",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"collection1",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32543_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32543"}}}},
[junit4:junit4]   1>   "router":"compositeId"}, control_collection=DocCollection(control_collection)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"1":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"control_collection",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32516_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32516",
[junit4:junit4]   1>           "leader":"true"}}}},
[junit4:junit4]   1>   "router":"compositeId"}}
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> ###### getShardId(3) in {collection1=DocCollection(collection1)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"2":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"collection1",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32543_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32543",
[junit4:junit4]   1>           "leader":"true"}}}},
[junit4:junit4]   1>   "router":"compositeId"}, control_collection=DocCollection(control_collection)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"1":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"control_collection",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32516_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32516",
[junit4:junit4]   1>           "leader":"true"}}}},
[junit4:junit4]   1>   "router":"compositeId"}}
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> ###### getShardId(3) in {collection1=DocCollection(collection1)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"2":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"collection1",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32543_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32543",
[junit4:junit4]   1>           "leader":"true"}}}},
[junit4:junit4]   1>   "router":"compositeId"}, control_collection=DocCollection(control_collection)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"1":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"control_collection",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32516_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32516",
[junit4:junit4]   1>           "leader":"true"}}}},
[junit4:junit4]   1>   "router":"compositeId"}}
[junit4:junit4]   1> ###### getShardId(3) in {collection1=DocCollection(collection1)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{
[junit4:junit4]   1>         "2":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"collection1",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32543_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32543",
[junit4:junit4]   1>           "leader":"true"},
[junit4:junit4]   1>         "3":{
[junit4:junit4]   1>           "state":"down",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"collection1",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32549_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32549"}}}},
[junit4:junit4]   1>   "router":"compositeId"}, control_collection=DocCollection(control_collection)={
[junit4:junit4]   1>   "shards":{"shard1":{
[junit4:junit4]   1>       "range":"80000000-7fffffff",
[junit4:junit4]   1>       "state":"active",
[junit4:junit4]   1>       "replicas":{"1":{
[junit4:junit4]   1>           "shard":"shard1",
[junit4:junit4]   1>           "state":"active",
[junit4:junit4]   1>           "core":"collection1",
[junit4:junit4]   1>           "collection":"control_collection",
[junit4:junit4]   1>           "node_name":"127.0.0.1:32516_",
[junit4:junit4]   1>           "base_url":"http://127.0.0.1:32516",
[junit4:junit4]   1>           "leader":"true"}}}},
[junit4:junit4]   1>   "router":"compositeId"}}
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   2> 22494 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1428071892459192320)]} 0 2
[junit4:junit4]   2> 22495 T485 C2 P32543 /update {wt=javabin&version=2} {add=[12 (1428071892459192320)]} 0 9
[junit4:junit4]   2> 22496 T475 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22497 T475 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "shard":"shard1",
[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:32549_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:32549"}
[junit4:junit4]   2> 22498 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10012 (1428071892461289472)]} 0 3
[junit4:junit4]   2> 22499 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10012 (1428071892461289472)]} 0 12
[junit4:junit4]   2> 22503 T465 C1 P32516 /update {wt=javabin&version=2} {add=[13 (1428071892472823808)]} 0 3
[junit4:junit4]   2> 22505 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10013 (1428071892475969536)]} 0 3
[junit4:junit4]   2> 22511 T480 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> 22511 T474 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> 22511 T508 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> 22511 T493 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>  C0_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:32549_, base_url=http://127.0.0.1:32549}
[junit4:junit4]   2> 22515 T499 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1428071892480163840)]} 0 3
[junit4:junit4]   2> 22516 T484 C2 P32543 /update {wt=javabin&version=2} {add=[13 (1428071892480163840)]} 0 10
[junit4:junit4]   2> 22517 T498 C0 P32549 /update {distrib.from=http://127.0.0.1:32543/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10013 (1428071892482260992)]} 0 2
[junit4:junit4]   2> 22518 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10013 (1428071892482260992)]} 0 10
[junit4:junit4]   2> 22522 T464 C1 P32516 /update {wt=javabin&version=2} {add=[14 (1428071892493795328)]} 0 3
[junit4:junit4]   2> 22524 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10014 (1428071892495892480)]} 0 3
[junit4:junit4]   2> 22529 T485 C2 P32543 /update {wt=javabin&version=2} {add=[14 (1428071892500086784)]} 0 4
[junit4:junit4]   2> 22531 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10014 (1428071892502183936)]} 0 3
[junit4:junit4]   2> 22535 T465 C1 P32516 /update {wt=javabin&version=2} {add=[15 (1428071892507426816)]} 0 3
[junit4:junit4]   2> 22537 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10015 (1428071892509523968)]} 0 3
[junit4:junit4]   2> 22541 T484 C2 P32543 /update {wt=javabin&version=2} {add=[15 (1428071892513718272)]} 0 3
[junit4:junit4]   2> 22543 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10015 (1428071892515815424)]} 0 3
[junit4:junit4]   2> 22547 T464 C1 P32516 /update {wt=javabin&version=2} {add=[16 (1428071892520009728)]} 0 3
[junit4:junit4]   2> 22549 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10016 (1428071892522106880)]} 0 2
[junit4:junit4]   2> 22553 T485 C2 P32543 /update {wt=javabin&version=2} {add=[16 (1428071892526301184)]} 0 2
[junit4:junit4]   2> 22555 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10016 (1428071892528398336)]} 0 3
[junit4:junit4]   2> 22559 T465 C1 P32516 /update {wt=javabin&version=2} {add=[17 (1428071892532592640)]} 0 3
[junit4:junit4]   2> 22561 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10017 (1428071892534689792)]} 0 3
[junit4:junit4]   2> 22565 T484 C2 P32543 /update {wt=javabin&version=2} {add=[17 (1428071892538884096)]} 0 3
[junit4:junit4]   2> 22567 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10017 (1428071892540981248)]} 0 3
[junit4:junit4]   2> 22569 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[16 (-1428071892545175552)]} 0 1
[junit4:junit4]   2> 22571 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10016 (-1428071892547272704)]} 0 1
[junit4:junit4]   2> 22573 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[16 (-1428071892549369856)]} 0 1
[junit4:junit4]   2> 22575 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10016 (-1428071892551467008)]} 0 1
[junit4:junit4]   2> 22580 T465 C1 P32516 /update {wt=javabin&version=2} {add=[18 (1428071892553564160)]} 0 3
[junit4:junit4]   2> 22581 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10018 (1428071892555661312)]} 0 3
[junit4:junit4]   2> 22586 T484 C2 P32543 /update {wt=javabin&version=2} {add=[18 (1428071892560904192)]} 0 2
[junit4:junit4]   2> 22588 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10018 (1428071892561952768)]} 0 4
[junit4:junit4]   2> 22592 T464 C1 P32516 /update {wt=javabin&version=2} {add=[19 (1428071892567195648)]} 0 2
[junit4:junit4]   2> 22594 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10019 (1428071892569292800)]} 0 3
[junit4:junit4]   2> 22598 T485 C2 P32543 /update {wt=javabin&version=2} {add=[19 (1428071892573487104)]} 0 3
[junit4:junit4]   2> 22600 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10019 (1428071892575584256)]} 0 3
[junit4:junit4]   2> 22602 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[18 (-1428071892579778560)]} 0 1
[junit4:junit4]   2> 22604 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10018 (-1428071892581875712)]} 0 1
[junit4:junit4]   2> 22606 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[18 (-1428071892583972864)]} 0 1
[junit4:junit4]   2> 22608 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10018 (-1428071892586070016)]} 0 1
[junit4:junit4]   2> 22612 T464 C1 P32516 /update {wt=javabin&version=2} {add=[20 (1428071892588167168)]} 0 3
[junit4:junit4]   2> 22614 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10020 (1428071892590264320)]} 0 3
[junit4:junit4]   2> 22618 T485 C2 P32543 /update {wt=javabin&version=2} {add=[20 (1428071892594458624)]} 0 3
[junit4:junit4]   2> 22620 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10020 (1428071892596555776)]} 0 3
[junit4:junit4]   2> 22624 T465 C1 P32516 /update {wt=javabin&version=2} {add=[21 (1428071892600750080)]} 0 3
[junit4:junit4]   2> 22626 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10021 (1428071892602847232)]} 0 3
[junit4:junit4]   2> 22630 T484 C2 P32543 /update {wt=javabin&version=2} {add=[21 (1428071892607041536)]} 0 3
[junit4:junit4]   2> 22632 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10021 (1428071892609138688)]} 0 3
[junit4:junit4]   2> 22636 T464 C1 P32516 /update {wt=javabin&version=2} {add=[22 (1428071892613332992)]} 0 3
[junit4:junit4]   2> 22638 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10022 (1428071892615430144)]} 0 3
[junit4:junit4]   2> 22642 T485 C2 P32543 /update {wt=javabin&version=2} {add=[22 (1428071892619624448)]} 0 3
[junit4:junit4]   2> 22644 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10022 (1428071892621721600)]} 0 3
[junit4:junit4]   2> 22648 T465 C1 P32516 /update {wt=javabin&version=2} {add=[23 (1428071892625915904)]} 0 3
[junit4:junit4]   2> 22650 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10023 (1428071892628013056)]} 0 2
[junit4:junit4]   2> 22654 T484 C2 P32543 /update {wt=javabin&version=2} {add=[23 (1428071892632207360)]} 0 3
[junit4:junit4]   2> 22657 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10023 (1428071892634304512)]} 0 4
[junit4:junit4]   2> 22660 T464 C1 P32516 /update {wt=javabin&version=2} {add=[24 (1428071892638498816)]} 0 3
[junit4:junit4]   2> 22663 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10024 (1428071892641644544)]} 0 3
[junit4:junit4]   2> 22666 T485 C2 P32543 /update {wt=javabin&version=2} {add=[24 (1428071892644790272)]} 0 3
[junit4:junit4]   2> 22669 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10024 (1428071892647936000)]} 0 3
[junit4:junit4]   2> 22672 T465 C1 P32516 /update {wt=javabin&version=2} {add=[25 (1428071892651081728)]} 0 3
[junit4:junit4]   2> 22675 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10025 (1428071892654227456)]} 0 3
[junit4:junit4]   2> 22679 T484 C2 P32543 /update {wt=javabin&version=2} {add=[25 (1428071892658421760)]} 0 3
[junit4:junit4]   2> 22681 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10025 (1428071892660518912)]} 0 3
[junit4:junit4]   2> 22685 T464 C1 P32516 /update {wt=javabin&version=2} {add=[26 (1428071892664713216)]} 0 3
[junit4:junit4]   2> 22688 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10026 (1428071892667858944)]} 0 2
[junit4:junit4]   2> 22691 T485 C2 P32543 /update {wt=javabin&version=2} {add=[26 (1428071892671004672)]} 0 3
[junit4:junit4]   2> 22696 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10026 (1428071892675198976)]} 0 3
[junit4:junit4]   2> 22699 T465 C1 P32516 /update {wt=javabin&version=2} {add=[27 (1428071892679393280)]} 0 4
[junit4:junit4]   2> 22702 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10027 (1428071892682539008)]} 0 3
[junit4:junit4]   2> 22705 T484 C2 P32543 /update {wt=javabin&version=2} {add=[27 (1428071892685684736)]} 0 2
[junit4:junit4]   2> 22709 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10027 (1428071892689879040)]} 0 3
[junit4:junit4]   2> 22711 T464 C1 P32516 /update {wt=javabin&version=2} {add=[28 (1428071892691976192)]} 0 3
[junit4:junit4]   2> 22716 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10028 (1428071892697219072)]} 0 3
[junit4:junit4]   2> 22717 T485 C2 P32543 /update {wt=javabin&version=2} {add=[28 (1428071892698267648)]} 0 2
[junit4:junit4]   2> 22722 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10028 (1428071892703510528)]} 0 3
[junit4:junit4]   2> 22723 T465 C1 P32516 /update {wt=javabin&version=2} {add=[29 (1428071892704559104)]} 0 3
[junit4:junit4]   2> 22728 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10029 (1428071892709801984)]} 0 3
[junit4:junit4]   2> 22729 T484 C2 P32543 /update {wt=javabin&version=2} {add=[29 (1428071892710850560)]} 0 3
[junit4:junit4]   2> 22734 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[29 (-1428071892718190592)]} 0 1
[junit4:junit4]   2> 22736 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10029 (1428071892716093440)]} 0 5
[junit4:junit4]   2> 22739 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[29 (-1428071892723433472)]} 0 1
[junit4:junit4]   2> 22740 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10029 (-1428071892724482048)]} 0 1
[junit4:junit4]   2> 22744 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10029 (-1428071892728676352)]} 0 1
[junit4:junit4]   2> 22745 T465 C1 P32516 /update {wt=javabin&version=2} {add=[30 (1428071892727627776)]} 0 3
[junit4:junit4]   2> 22750 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10030 (1428071892732870656)]} 0 3
[junit4:junit4]   2> 22751 T484 C2 P32543 /update {wt=javabin&version=2} {add=[30 (1428071892733919232)]} 0 2
[junit4:junit4]   2> 22756 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[30 (-1428071892740210688)]} 0 1
[junit4:junit4]   2> 22757 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10030 (1428071892739162112)]} 0 3
[junit4:junit4]   2> 22760 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[30 (-1428071892745453568)]} 0 1
[junit4:junit4]   2> 22761 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10030 (-1428071892746502144)]} 0 1
[junit4:junit4]   2> 22765 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10030 (-1428071892750696448)]} 0 1
[junit4:junit4]   2> 22766 T465 C1 P32516 /update {wt=javabin&version=2} {add=[31 (1428071892749647872)]} 0 3
[junit4:junit4]   2> 22771 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10031 (1428071892754890752)]} 0 3
[junit4:junit4]   2> 22772 T484 C2 P32543 /update {wt=javabin&version=2} {add=[31 (1428071892755939328)]} 0 3
[junit4:junit4]   2> 22776 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[31 (-1428071892762230784)]} 0 1
[junit4:junit4]   2> 22777 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10031 (1428071892761182208)]} 0 3
[junit4:junit4]   2> 22780 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[31 (-1428071892766425088)]} 0 1
[junit4:junit4]   2> 22781 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10031 (-1428071892767473664)]} 0 1
[junit4:junit4]   2> 22785 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10031 (-1428071892771667968)]} 0 0
[junit4:junit4]   2> 22786 T465 C1 P32516 /update {wt=javabin&version=2} {add=[32 (1428071892770619392)]} 0 3
[junit4:junit4]   2> 22791 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10032 (1428071892775862272)]} 0 3
[junit4:junit4]   2> 22791 T484 C2 P32543 /update {wt=javabin&version=2} {add=[32 (1428071892776910848)]} 0 2
[junit4:junit4]   2> 22797 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10032 (1428071892782153728)]} 0 3
[junit4:junit4]   2> 22797 T464 C1 P32516 /update {wt=javabin&version=2} {add=[33 (1428071892782153728)]} 0 3
[junit4:junit4]   2> 22803 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10033 (1428071892788445184)]} 0 3
[junit4:junit4]   2> 22803 T485 C2 P32543 /update {wt=javabin&version=2} {add=[33 (1428071892788445184)]} 0 3
[junit4:junit4]   2> 22809 T464 C1 P32516 /update {wt=javabin&version=2} {add=[34 (1428071892794736640)]} 0 3
[junit4:junit4]   2> 22809 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10033 (1428071892794736640)]} 0 2
[junit4:junit4]   2> 22815 T484 C2 P32543 /update {wt=javabin&version=2} {add=[34 (1428071892801028096)]} 0 3
[junit4:junit4]   2> 22816 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10034 (1428071892802076672)]} 0 3
[junit4:junit4]   2> 22819 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[32 (-1428071892807319552)]} 0 1
[junit4:junit4]   2> 22821 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10034 (1428071892808368128)]} 0 2
[junit4:junit4]   2> 22825 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[32 (-1428071892813611008)]} 0 1
[junit4:junit4]   2> 22826 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10032 (-1428071892814659584)]} 0 1
[junit4:junit4]   2> 22831 T464 C1 P32516 /update {wt=javabin&version=2} {add=[35 (1428071892817805312)]} 0 3
[junit4:junit4]   2> 22831 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10032 (-1428071892819902464)]} 0 1
[junit4:junit4]   2> 22837 T485 C2 P32543 /update {wt=javabin&version=2} {add=[35 (1428071892824096768)]} 0 3
[junit4:junit4]   2> 22837 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10035 (1428071892824096768)]} 0 2
[junit4:junit4]   2> 22841 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[33 (-1428071892830388224)]} 0 1
[junit4:junit4]   2> 22843 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10035 (1428071892830388224)]} 0 2
[junit4:junit4]   2> 22845 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[33 (-1428071892834582528)]} 0 0
[junit4:junit4]   2> 22847 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10033 (-1428071892836679680)]} 0 1
[junit4:junit4]   2> 22851 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10033 (-1428071892840873984)]} 0 1
[junit4:junit4]   2> 22852 T465 C1 P32516 /update {wt=javabin&version=2} {add=[36 (1428071892839825408)]} 0 3
[junit4:junit4]   2> 22857 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10036 (1428071892845068288)]} 0 3
[junit4:junit4]   2> 22858 T484 C2 P32543 /update {wt=javabin&version=2} {add=[36 (1428071892846116864)]} 0 3
[junit4:junit4]   2> 22863 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10036 (1428071892851359744)]} 0 3
[junit4:junit4]   2> 22864 T464 C1 P32516 /update {wt=javabin&version=2} {add=[37 (1428071892852408320)]} 0 3
[junit4:junit4]   2> 22869 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10037 (1428071892857651200)]} 0 3
[junit4:junit4]   2> 22870 T485 C2 P32543 /update {wt=javabin&version=2} {add=[37 (1428071892858699776)]} 0 3
[junit4:junit4]   2> 22877 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10037 (1428071892864991232)]} 0 3
[junit4:junit4]   2> 22877 T465 C1 P32516 /update {wt=javabin&version=2} {add=[38 (1428071892866039808)]} 0 3
[junit4:junit4]   2> 22883 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10038 (1428071892872331264)]} 0 3
[junit4:junit4]   2> 22883 T484 C2 P32543 /update {wt=javabin&version=2} {add=[38 (1428071892872331264)]} 0 2
[junit4:junit4]   2> 22889 T464 C1 P32516 /update {wt=javabin&version=2} {add=[39 (1428071892878622720)]} 0 2
[junit4:junit4]   2> 22889 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10038 (1428071892878622720)]} 0 3
[junit4:junit4]   2> 22894 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10039 (1428071892884914176)]} 0 2
[junit4:junit4]   2> 22895 T485 C2 P32543 /update {wt=javabin&version=2} {add=[39 (1428071892884914176)]} 0 3
[junit4:junit4]   2> 22901 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10039 (1428071892891205632)]} 0 3
[junit4:junit4]   2> 22901 T464 C1 P32516 /update {wt=javabin&version=2} {add=[40 (1428071892891205632)]} 0 2
[junit4:junit4]   2> 22907 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10040 (1428071892897497088)]} 0 3
[junit4:junit4]   2> 22907 T484 C2 P32543 /update {wt=javabin&version=2} {add=[40 (1428071892897497088)]} 0 3
[junit4:junit4]   2> 22913 T464 C1 P32516 /update {wt=javabin&version=2} {add=[41 (1428071892903788544)]} 0 3
[junit4:junit4]   2> 22913 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10040 (1428071892903788544)]} 0 3
[junit4:junit4]   2> 22919 T485 C2 P32543 /update {wt=javabin&version=2} {add=[41 (1428071892910080000)]} 0 3
[junit4:junit4]   2> 22919 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10041 (1428071892910080000)]} 0 2
[junit4:junit4]   2> 22925 T465 C1 P32516 /update {wt=javabin&version=2} {add=[42 (1428071892916371456)]} 0 3
[junit4:junit4]   2> 22925 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10041 (1428071892916371456)]} 0 2
[junit4:junit4]   2> 22931 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10042 (1428071892922662912)]} 0 3
[junit4:junit4]   2> 22931 T484 C2 P32543 /update {wt=javabin&version=2} {add=[42 (1428071892922662912)]} 0 3
[junit4:junit4]   2> 22937 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10042 (1428071892928954368)]} 0 3
[junit4:junit4]   2> 22937 T465 C1 P32516 /update {wt=javabin&version=2} {add=[43 (1428071892928954368)]} 0 3
[junit4:junit4]   2> 22943 T485 C2 P32543 /update {wt=javabin&version=2} {add=[43 (1428071892935245824)]} 0 2
[junit4:junit4]   2> 22943 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10043 (1428071892935245824)]} 0 3
[junit4:junit4]   2> 22947 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[34 (-1428071892941537280)]} 0 1
[junit4:junit4]   2> 22949 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10043 (1428071892941537280)]} 0 3
[junit4:junit4]   2> 22953 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10034 (-1428071892947828736)]} 0 1
[junit4:junit4]   2> 22953 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[34 (-1428071892947828736)]} 0 0
[junit4:junit4]   2> 22957 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10034 (-1428071892952023040)]} 0 1
[junit4:junit4]   2> 22960 T465 C1 P32516 /update {wt=javabin&version=2} {add=[44 (1428071892953071616)]} 0 3
[junit4:junit4]   2> 22962 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10044 (1428071892956217344)]} 0 2
[junit4:junit4]   2> 22966 T484 C2 P32543 /update {wt=javabin&version=2} {add=[44 (1428071892959363072)]} 0 3
[junit4:junit4]   2> 22968 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10044 (1428071892961460224)]} 0 2
[junit4:junit4]   2> 22970 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[37 (-1428071892964605952)]} 0 1
[junit4:junit4]   2> 22972 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10037 (-1428071892966703104)]} 0 1
[junit4:junit4]   2> 22974 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[37 (-1428071892969848832)]} 0 1
[junit4:junit4]   2> 22976 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10037 (-1428071892971945984)]} 0 1
[junit4:junit4]   2> 22980 T465 C1 P32516 /update {wt=javabin&version=2} {add=[45 (1428071892974043136)]} 0 3
[junit4:junit4]   2> 22981 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10045 (1428071892976140288)]} 0 2
[junit4:junit4]   2> 22986 T484 C2 P32543 /update {wt=javabin&version=2} {add=[45 (1428071892980334592)]} 0 3
[junit4:junit4]   2> 22988 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10045 (1428071892982431744)]} 0 3
[junit4:junit4]   2> 22992 T464 C1 P32516 /update {wt=javabin&version=2} {add=[46 (1428071892986626048)]} 0 3
[junit4:junit4]   2> 22994 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10046 (1428071892988723200)]} 0 2
[junit4:junit4]   2> 22998 T485 C2 P32543 /update {wt=javabin&version=2} {add=[46 (1428071892992917504)]} 0 2
[junit4:junit4]   2> 23000 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10046 (1428071892995014656)]} 0 3
[junit4:junit4]   2> 23003 T465 C1 P32516 /update {wt=javabin&version=2} {add=[47 (1428071892999208960)]} 0 2
[junit4:junit4]   2> 23006 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10047 (1428071893001306112)]} 0 3
[junit4:junit4]   2> 23008 T484 C2 P32543 /update {wt=javabin&version=2} {add=[47 (1428071893004451840)]} 0 2
[junit4:junit4]   2> 23012 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10047 (1428071893007597568)]} 0 2
[junit4:junit4]   2> 23016 T464 C1 P32516 /update {wt=javabin&version=2} {add=[48 (1428071893010743296)]} 0 4
[junit4:junit4]   2> 23019 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10048 (1428071893014937600)]} 0 3
[junit4:junit4]   2> 23022 T485 C2 P32543 /update {wt=javabin&version=2} {add=[48 (1428071893018083328)]} 0 3
[junit4:junit4]   2> 23025 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10048 (1428071893022277632)]} 0 2
[junit4:junit4]   2> 23028 T465 C1 P32516 /update {wt=javabin&version=2} {add=[49 (1428071893024374784)]} 0 3
[junit4:junit4]   2> 23031 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10049 (1428071893027520512)]} 0 3
[junit4:junit4]   2> 23034 T484 C2 P32543 /update {wt=javabin&version=2} {add=[49 (1428071893030666240)]} 0 3
[junit4:junit4]   2> 23036 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10049 (1428071893033811968)]} 0 2
[junit4:junit4]   2> 23039 T464 C1 P32516 /update {wt=javabin&version=2} {add=[50 (1428071893036957696)]} 0 2
[junit4:junit4]   2> 23042 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10050 (1428071893039054848)]} 0 3
[junit4:junit4]   2> 23045 T485 C2 P32543 /update {wt=javabin&version=2} {add=[50 (1428071893043249152)]} 0 2
[junit4:junit4]   2> 23048 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10050 (1428071893046394880)]} 0 2
[junit4:junit4]   2> 23049 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[38 (-1428071893048492032)]} 0 1
[junit4:junit4]   2> 23052 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10038 (-1428071893050589184)]} 0 1
[junit4:junit4]   2> 23053 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[38 (-1428071893052686336)]} 0 1
[junit4:junit4]   2> 23056 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10038 (-1428071893055832064)]} 0 0
[junit4:junit4]   2> 23060 T464 C1 P32516 /update {wt=javabin&version=2} {add=[51 (1428071893056880640)]} 0 3
[junit4:junit4]   2> 23063 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10051 (1428071893061074944)]} 0 3
[junit4:junit4]   2> 23066 T485 C2 P32543 /update {wt=javabin&version=2} {add=[51 (1428071893065269248)]} 0 2
[junit4:junit4]   2> 23069 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10051 (1428071893067366400)]} 0 3
[junit4:junit4]   2> 23072 T465 C1 P32516 /update {wt=javabin&version=2} {add=[52 (1428071893070512128)]} 0 3
[junit4:junit4]   2> 23075 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10052 (1428071893073657856)]} 0 2
[junit4:junit4]   2> 23077 T484 C2 P32543 /update {wt=javabin&version=2} {add=[52 (1428071893076803584)]} 0 2
[junit4:junit4]   2> 23081 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10052 (1428071893079949312)]} 0 3
[junit4:junit4]   2> 23081 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[41 (-1428071893080997888)]} 0 1
[junit4:junit4]   2> 23085 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10041 (-1428071893086240768)]} 0 1
[junit4:junit4]   2> 23086 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[41 (-1428071893086240768)]} 0 1
[junit4:junit4]   2> 23090 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10041 (-1428071893091483648)]} 0 1
[junit4:junit4]   2> 23091 T465 C1 P32516 /update {wt=javabin&version=2} {add=[53 (1428071893091483648)]} 0 2
[junit4:junit4]   2> 23096 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10053 (1428071893095677952)]} 0 3
[junit4:junit4]   2> 23097 T485 C2 P32543 /update {wt=javabin&version=2} {add=[53 (1428071893096726528)]} 0 3
[junit4:junit4]   2> 23101 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[42 (-1428071893103017984)]} 0 1
[junit4:junit4]   2> 23102 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10053 (1428071893101969408)]} 0 3
[junit4:junit4]   2> 23105 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[42 (-1428071893107212288)]} 0 1
[junit4:junit4]   2> 23106 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10042 (-1428071893108260864)]} 0 1
[junit4:junit4]   2> 23110 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10042 (-1428071893112455168)]} 0 1
[junit4:junit4]   2> 23110 T465 C1 P32516 /update {wt=javabin&version=2} {add=[54 (1428071893111406592)]} 0 2
[junit4:junit4]   2> 23116 T485 C2 P32543 /update {wt=javabin&version=2} {add=[54 (1428071893116649472)]} 0 3
[junit4:junit4]   2> 23116 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10054 (1428071893116649472)]} 0 3
[junit4:junit4]   2> 23120 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[44 (-1428071893122940928)]} 0 0
[junit4:junit4]   2> 23122 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10054 (1428071893122940928)]} 0 3
[junit4:junit4]   2> 23124 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[44 (-1428071893126086656)]} 0 1
[junit4:junit4]   2> 23126 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10044 (-1428071893129232384)]} 0 1
[junit4:junit4]   2> 23129 T464 C1 P32516 /update {wt=javabin&version=2} {add=[55 (1428071893131329536)]} 0 2
[junit4:junit4]   2> 23130 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10044 (-1428071893133426688)]} 0 1
[junit4:junit4]   2> 23136 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10055 (1428071893137620992)]} 0 3
[junit4:junit4]   2> 23136 T485 C2 P32543 /update {wt=javabin&version=2} {add=[55 (1428071893137620992)]} 0 3
[junit4:junit4]   2> 23142 T464 C1 P32516 /update {wt=javabin&version=2} {add=[56 (1428071893143912448)]} 0 2
[junit4:junit4]   2> 23142 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10055 (1428071893143912448)]} 0 3
[junit4:junit4]   2> 23147 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10056 (1428071893150203904)]} 0 2
[junit4:junit4]   2> 23148 T484 C2 P32543 /update {wt=javabin&version=2} {add=[56 (1428071893150203904)]} 0 2
[junit4:junit4]   2> 23153 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10056 (1428071893155446784)]} 0 3
[junit4:junit4]   2> 23155 T464 C1 P32516 /update {wt=javabin&version=2} {add=[57 (1428071893157543936)]} 0 3
[junit4:junit4]   2> 23158 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10057 (1428071893161738240)]} 0 2
[junit4:junit4]   2> 23161 T485 C2 P32543 /update {wt=javabin&version=2} {add=[57 (1428071893163835392)]} 0 3
[junit4:junit4]   2> 23164 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10057 (1428071893166981120)]} 0 3
[junit4:junit4]   2> 23168 T465 C1 P32516 /update {wt=javabin&version=2} {add=[58 (1428071893170126848)]} 0 3
[junit4:junit4]   2> 23171 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10058 (1428071893174321152)]} 0 3
[junit4:junit4]   2> 23173 T484 C2 P32543 /update {wt=javabin&version=2} {add=[58 (1428071893177466880)]} 0 2
[junit4:junit4]   2> 23177 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10058 (1428071893180612608)]} 0 3
[junit4:junit4]   2> 23179 T464 C1 P32516 /update {wt=javabin&version=2} {add=[59 (1428071893182709760)]} 0 3
[junit4:junit4]   2> 23182 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10059 (1428071893186904064)]} 0 2
[junit4:junit4]   2> 23185 T485 C2 P32543 /update {wt=javabin&version=2} {add=[59 (1428071893189001216)]} 0 3
[junit4:junit4]   2> 23187 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10059 (1428071893192146944)]} 0 2
[junit4:junit4]   2> 23191 T465 C1 P32516 /update {wt=javabin&version=2} {add=[60 (1428071893195292672)]} 0 3
[junit4:junit4]   2> 23193 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10060 (1428071893197389824)]} 0 3
[junit4:junit4]   2> 23196 T484 C2 P32543 /update {wt=javabin&version=2} {add=[60 (1428071893201584128)]} 0 2
[junit4:junit4]   2> 23199 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10060 (1428071893203681280)]} 0 3
[junit4:junit4]   2> 23200 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[45 (-1428071893206827008)]} 0 1
[junit4:junit4]   2> 23203 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10045 (-1428071893209972736)]} 0 1
[junit4:junit4]   2> 23204 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[45 (-1428071893211021312)]} 0 0
[junit4:junit4]   2> 23208 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10045 (-1428071893215215616)]} 0 1
[junit4:junit4]   2> 23210 T465 C1 P32516 /update {wt=javabin&version=2} {add=[61 (1428071893215215616)]} 0 3
[junit4:junit4]   2> 23214 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10061 (1428071893219409920)]} 0 3
[junit4:junit4]   2> 23216 T484 C2 P32543 /update {wt=javabin&version=2} {add=[61 (1428071893221507072)]} 0 2
[junit4:junit4]   2> 23219 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10061 (1428071893225701376)]} 0 2
[junit4:junit4]   2> 23221 T464 C1 P32516 /update {wt=javabin&version=2} {add=[62 (1428071893227798528)]} 0 2
[junit4:junit4]   2> 23226 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10062 (1428071893231992832)]} 0 3
[junit4:junit4]   2> 23226 T485 C2 P32543 /update {wt=javabin&version=2} {add=[62 (1428071893233041408)]} 0 2
[junit4:junit4]   2> 23233 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10062 (1428071893238284288)]} 0 4
[junit4:junit4]   2> 23233 T465 C1 P32516 /update {wt=javabin&version=2} {add=[63 (1428071893239332864)]} 0 4
[junit4:junit4]   2> 23241 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10063 (1428071893246672896)]} 0 4
[junit4:junit4]   2> 23241 T484 C2 P32543 /update {wt=javabin&version=2} {add=[63 (1428071893246672896)]} 0 4
[junit4:junit4]   2> 23247 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10063 (1428071893254012928)]} 0 3
[junit4:junit4]   2> 23247 T465 C1 P32516 /update {wt=javabin&version=2} {add=[64 (1428071893254012928)]} 0 3
[junit4:junit4]   2> 23254 T484 C2 P32543 /update {wt=javabin&version=2} {add=[64 (1428071893260304384)]} 0 4
[junit4:junit4]   2> 23254 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10064 (1428071893260304384)]} 0 4
[junit4:junit4]   2> 23258 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[46 (-1428071893267644416)]} 0 1
[junit4:junit4]   2> 23259 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10064 (1428071893267644416)]} 0 2
[junit4:junit4]   2> 23263 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10046 (-1428071893271838720)]} 0 1
[junit4:junit4]   2> 23263 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[46 (-1428071893272887296)]} 0 1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:1
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   1> coreNodeName:2
[junit4:junit4]   2> 23268 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10046 (-1428071893278130176)]} 0 1
[junit4:junit4]   2> 23270 T464 C1 P32516 /update {wt=javabin&version=2} {add=[65 (1428071893279178752)]} 0 3
[junit4:junit4]   2> 23275 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10065 (1428071893283373056)]} 0 3
[junit4:junit4]   2> 23276 T484 C2 P32543 /update {wt=javabin&version=2} {add=[65 (1428071893284421632)]} 0 3
[junit4:junit4]   2> 23279 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10065 (1428071893288615936)]} 0 2
[junit4:junit4]   2> 23281 T465 C1 P32516 /update {wt=javabin&version=2} {add=[66 (1428071893290713088)]} 0 2
[junit4:junit4]   2> 23284 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10066 (1428071893293858816)]} 0 2
[junit4:junit4]   2> 23286 T485 C2 P32543 /update {wt=javabin&version=2} {add=[66 (1428071893295955968)]} 0 2
[junit4:junit4]   2> 23289 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10066 (1428071893299101696)]} 0 2
[junit4:junit4]   2> 23291 T464 C1 P32516 /update {wt=javabin&version=2} {add=[67 (1428071893301198848)]} 0 2
[junit4:junit4]   2> 23294 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10067 (1428071893304344576)]} 0 2
[junit4:junit4]   2> 23296 T484 C2 P32543 /update {wt=javabin&version=2} {add=[67 (1428071893306441728)]} 0 2
[junit4:junit4]   2> 23308 T465 C1 P32516 /update {wt=javabin&version=2} {add=[68 (1428071893311684608)]} 0 9
[junit4:junit4]   2> 23326 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10067 (1428071893310636032)]} 0 28
[junit4:junit4]   2> 23327 T484 C2 P32543 /update {wt=javabin&version=2} {add=[68 (1428071893324267520)]} 0 16
[junit4:junit4]   2> 23330 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[47 (-1428071893343141889)]} 0 0
[junit4:junit4]   2> 23331 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10068 (1428071893343141888)]} 0 2
[junit4:junit4]   2> 23334 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[47 (-1428071893346287616)]} 0 1
[junit4:junit4]   2> 23336 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10068 (1428071893348384768)]} 0 2
[junit4:junit4]   2> 23339 T465 C1 P32516 /update {wt=javabin&version=2} {add=[69 (1428071893351530496)]} 0 2
[junit4:junit4]   2> 23340 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10047 (-1428071893353627648)]} 0 1
[junit4:junit4]   2> 23344 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10047 (-1428071893356773377)]} 0 1
[junit4:junit4]   2> 23344 T485 C2 P32543 /update {wt=javabin&version=2} {add=[69 (1428071893356773376)]} 0 2
[junit4:junit4]   2> 23349 T465 C1 P32516 /update {wt=javabin&version=2} {add=[70 (1428071893362016256)]} 0 2
[junit4:junit4]   2> 23349 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10069 (1428071893362016257)]} 0 1
[junit4:junit4]   2> 23354 T485 C2 P32543 /update {wt=javabin&version=2} {add=[70 (1428071893367259136)]} 0 2
[junit4:junit4]   2> 23355 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10069 (1428071893368307712)]} 0 2
[junit4:junit4]   2> 23358 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[49 (-1428071893371453440)]} 0 1
[junit4:junit4]   2> 23360 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10070 (1428071893373550592)]} 0 2
[junit4:junit4]   2> 23361 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[49 (-1428071893374599168)]} 0 1
[junit4:junit4]   2> 23366 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10070 (1428071893378793472)]} 0 2
[junit4:junit4]   2> 23366 T465 C1 P32516 /update {wt=javabin&version=2} {add=[71 (1428071893379842048)]} 0 2
[junit4:junit4]   2> 23370 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10049 (-1428071893385084928)]} 0 1
[junit4:junit4]   2> 23371 T485 C2 P32543 /update {wt=javabin&version=2} {add=[71 (1428071893385084928)]} 0 2
[junit4:junit4]   2> 23375 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[50 (-1428071893389279232)]} 0 1
[junit4:junit4]   2> 23375 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10049 (-1428071893390327808)]} 0 1
[junit4:junit4]   2> 23379 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[50 (-1428071893394522112)]} 0 0
[junit4:junit4]   2> 23381 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10071 (1428071893394522112)]} 0 2
[junit4:junit4]   2> 23384 T465 C1 P32516 /update {wt=javabin&version=2} {add=[72 (1428071893398716416)]} 0 2
[junit4:junit4]   2> 23386 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10071 (1428071893400813568)]} 0 2
[junit4:junit4]   2> 23389 T484 C2 P32543 /update {wt=javabin&version=2} {add=[72 (1428071893403959296)]} 0 2
[junit4:junit4]   2> 23390 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10050 (-1428071893406056448)]} 0 1
[junit4:junit4]   2> 23394 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10050 (-1428071893409202176)]} 0 1
[junit4:junit4]   2> 23394 T464 C1 P32516 /update {wt=javabin&version=2} {add=[73 (1428071893409202176)]} 0 2
[junit4:junit4]   2> 23399 T484 C2 P32543 /update {wt=javabin&version=2} {add=[73 (1428071893414445056)]} 0 2
[junit4:junit4]   2> 23399 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10072 (1428071893414445056)]} 0 2
[junit4:junit4]   2> 23403 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[51 (-1428071893418639360)]} 0 1
[junit4:junit4]   2> 23405 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10072 (1428071893420736512)]} 0 2
[junit4:junit4]   2> 23407 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[51 (-1428071893423882240)]} 0 1
[junit4:junit4]   2> 23410 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10073 (1428071893425979392)]} 0 2
[junit4:junit4]   2> 23412 T465 C1 P32516 /update {wt=javabin&version=2} {add=[74 (1428071893428076544)]} 0 2
[junit4:junit4]   2> 23416 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10073 (1428071893431222272)]} 0 2
[junit4:junit4]   2> 23418 T484 C2 P32543 /update {wt=javabin&version=2} {add=[74 (1428071893434368000)]} 0 2
[junit4:junit4]   2> 23420 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10051 (-1428071893436465152)]} 0 1
[junit4:junit4]   2> 23423 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10051 (-1428071893439610880)]} 0 1
[junit4:junit4]   2> 23423 T464 C1 P32516 /update {wt=javabin&version=2} {add=[75 (1428071893439610880)]} 0 2
[junit4:junit4]   2> 23427 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10074 (1428071893443805184)]} 0 2
[junit4:junit4]   2> 23429 T484 C2 P32543 /update {wt=javabin&version=2} {add=[75 (1428071893445902336)]} 0 2
[junit4:junit4]   2> 23432 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10074 (1428071893449048064)]} 0 2
[junit4:junit4]   2> 23433 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[53 (-1428071893450096640)]} 0 1
[junit4:junit4]   2> 23437 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[53 (-1428071893454290944)]} 0 1
[junit4:junit4]   2> 23437 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10075 (1428071893454290944)]} 0 2
[junit4:junit4]   2> 23442 T465 C1 P32516 /update {wt=javabin&version=2} {add=[76 (1428071893459533824)]} 0 2
[junit4:junit4]   2> 23442 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10075 (1428071893459533824)]} 0 2
[junit4:junit4]   2> 23446 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10053 (-1428071893464776704)]} 0 0
[junit4:junit4]   2> 23447 T485 C2 P32543 /update {wt=javabin&version=2} {add=[76 (1428071893464776704)]} 0 2
[junit4:junit4]   2> 23451 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10053 (-1428071893468971008)]} 0 1
[junit4:junit4]   2> 23452 T465 C1 P32516 /update {wt=javabin&version=2} {add=[77 (1428071893470019584)]} 0 2
[junit4:junit4]   2> 23456 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10076 (1428071893474213888)]} 0 2
[junit4:junit4]   2> 23458 T484 C2 P32543 /update {wt=javabin&version=2} {add=[77 (1428071893476311040)]} 0 2
[junit4:junit4]   2> 23461 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10076 (1428071893479456768)]} 0 2
[junit4:junit4]   2> 23462 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[55 (-1428071893481553920)]} 0 1
[junit4:junit4]   2> 23466 T511 C0 P32549 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:32543/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 23466 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[55 (-1428071893484699648)]} 0 1
[junit4:junit4]   2> 23466 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10077 (1428071893484699648)]} 0 2
[junit4:junit4]   2> 23475 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10077 (1428071893489942528)]} 0 6
[junit4:junit4]   2> 23475 T464 C1 P32516 /update {wt=javabin&version=2} {add=[78 (1428071893489942528)]} 0 5
[junit4:junit4]   2> 23476 T511 C0 P32549 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4]   2> 23479 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10055 (-1428071893499379712)]} 0 1
[junit4:junit4]   2> 23481 T485 C2 P32543 /update {wt=javabin&version=2} {add=[78 (1428071893500428288)]} 0 2
[junit4:junit4]   2> 23483 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10055 (-1428071893502525440)]} 0 1
[junit4:junit4]   2> 23485 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[59 (-1428071893505671168)]} 0 1
[junit4:junit4]   2> 23488 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10078 (1428071893507768320)]} 0 2
[junit4:junit4]   2> 23489 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[59 (-1428071893508816896)]} 0 1
[junit4:junit4]   2> 23494 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10078 (1428071893514059776)]} 0 2
[junit4:junit4]   2> 23495 T464 C1 P32516 /update {wt=javabin&version=2} {add=[79 (1428071893514059776)]} 0 2
[junit4:junit4]   2> 23498 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10059 (-1428071893519302656)]} 0 1
[junit4:junit4]   2> 23500 T484 C2 P32543 /update {wt=javabin&version=2} {add=[79 (1428071893520351232)]} 0 2
[junit4:junit4]   2> 23502 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10059 (-1428071893522448384)]} 0 1
[junit4:junit4]   2> 23503 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[63 (-1428071893524545536)]} 0 0
[junit4:junit4]   2> 23507 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[63 (-1428071893527691264)]} 0 1
[junit4:junit4]   2> 23509 T511 C0 P32549 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:32549 START replicas=[http://127.0.0.1:32543/collection1/] nUpdates=100
[junit4:junit4]   2> 23510 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10079 (1428071893525594112)]} 0 6
[junit4:junit4]   2> 23542 T465 C1 P32516 /update {wt=javabin&version=2} {add=[80 (1428071893532934144)]} 0 32
[junit4:junit4]   2> 23562 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10079 (1428071893536079872)]} 0 49
[junit4:junit4]   2> 23566 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10063 (-1428071893590605824)]} 0 0
[junit4:junit4]   2> 23568 T511 C0 P32549 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 23569 T511 C0 P32549 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 23569 T511 C0 P32549 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 23570 T511 C0 P32549 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 23570 T511 C0 P32549 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 23570 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10063 (-1428071893594800128)]} 0 0
[junit4:junit4]   2> 23571 T511 C0 P32549 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:32543/collection1/. core=collection1
[junit4:junit4]   2> 23571 T511 C0 P32549 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 23573 T484 C2 P32543 /update {wt=javabin&version=2} {add=[80 (1428071893570682880)]} 0 26
[junit4:junit4]   2> 23582 T464 C1 P32516 /update {wt=javabin&version=2} {add=[81 (1428071893601091584)]} 0 6
[junit4:junit4]   2> 23582 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10080 (1428071893600043008)]} 0 8
[junit4:junit4]   2> 23584 T486 C2 P32543 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=9 
[junit4:junit4]   2> 23588 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10080 (1428071893612625920)]} 0 2
[junit4:junit4]   2> 23589 T485 C2 P32543 /update {wt=javabin&version=2} {add=[81 (1428071893612625921)]} 0 3
[junit4:junit4]   2> 23591 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10081 (1428071893615771648)]} 0 1
[junit4:junit4]   2> 23592 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[65 (-1428071893617868800)]} 0 0
[junit4:junit4]   2> 23597 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[65 (-1428071893623111680)]} 0 1
[junit4:junit4]   2> 23600 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10081 (1428071893621014528)]} 0 6
[junit4:junit4]   2> 23602 T465 C1 P32516 /update {wt=javabin&version=2} {add=[82 (1428071893627305984)]} 0 2
[junit4:junit4]   2> 23603 T487 C2 P32543 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 23603 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10065 (-1428071893629403136)]} 0 0
[junit4:junit4]   2> 23608 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10065 (-1428071893633597440)]} 0 1
[junit4:junit4]   2> 23627 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10082 (1428071893638840320)]} 0 16
[junit4:junit4]   2> 23627 T485 C2 P32543 /update {wt=javabin&version=2} {add=[82 (1428071893631500288)]} 0 22
[junit4:junit4]   2> 23632 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[66 (-1428071893658763264)]} 0 1
[junit4:junit4]   2> 23635 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[66 (-1428071893661908992)]} 0 1
[junit4:junit4]   2> 23645 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10082 (1428071893658763264)]} 0 15
[junit4:junit4]   2> 23646 T464 C1 P32516 /update {wt=javabin&version=2} {add=[83 (1428071893665054720)]} 0 9
[junit4:junit4]   2> 23650 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10066 (-1428071893677637632)]} 0 1
[junit4:junit4]   2> 23652 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10066 (-1428071893680783360)]} 0 0
[junit4:junit4]   2> 23654 T484 C2 P32543 /update {wt=javabin&version=2} {add=[83 (1428071893678686208)]} 0 5
[junit4:junit4]   2> 23656 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10083 (1428071893684977664)]} 0 1
[junit4:junit4]   2> 23658 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[68 (-1428071893687074816)]} 0 0
[junit4:junit4]   2> 23662 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[68 (-1428071893691269120)]} 0 0
[junit4:junit4]   2> 23668 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10083 (1428071893689171968)]} 0 8
[junit4:junit4]   2> 23668 T465 C1 P32516 /update {wt=javabin&version=2} {add=[84 (1428071893696512000)]} 0 2
[junit4:junit4]   2> 23673 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10068 (-1428071893701754880)]} 0 1
[junit4:junit4]   2> 23676 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10068 (-1428071893704900608)]} 0 0
[junit4:junit4]   2> 23679 T484 C2 P32543 /update {wt=javabin&version=2} {add=[84 (1428071893702803456)]} 0 7
[junit4:junit4]   2> 23679 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10084 (1428071893708046336)]} 0 1
[junit4:junit4]   2> 23682 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[69 (-1428071893712240640)]} 0 0
[junit4:junit4]   2> 23686 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[69 (-1428071893715386368)]} 0 1
[junit4:junit4]   2> 23703 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10084 (1428071893712240640)]} 0 21
[junit4:junit4]   2> 23703 T465 C1 P32516 /update {wt=javabin&version=2} {add=[85 (1428071893718532096)]} 0 15
[junit4:junit4]   2> 23707 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10069 (-1428071893737406464)]} 0 1
[junit4:junit4]   2> 23710 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10069 (-1428071893741600768)]} 0 0
[junit4:junit4]   2> 23725 T484 C2 P32543 /update {wt=javabin&version=2} {add=[85 (1428071893738455040)]} 0 19
[junit4:junit4]   2> 23725 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10085 (1428071893744746496)]} 0 12
[junit4:junit4]   2> 23765 T451 oasc.RecoveryStrategy.close WARNING Stopping recovery for zkNodeName=3core=collection1
[junit4:junit4]   2> 23783 T465 C1 P32516 /update {wt=javabin&version=2} {add=[86 (1428071893762572288)]} 0 54
[junit4:junit4]   2> 23784 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10085 (1428071893762572288)]} 0 55
[junit4:junit4]   2> 23802 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10086 (1428071893823389696)]} 0 15
[junit4:junit4]   2> 23802 T484 C2 P32543 /update {wt=javabin&version=2} {add=[86 (1428071893823389696)]} 0 14
[junit4:junit4]   2> 23850 T465 C1 P32516 /update {wt=javabin&version=2} {add=[87 (1428071893842264064)]} 0 45
[junit4:junit4]   2> 23850 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10086 (1428071893842264064)]} 0 45
[junit4:junit4]   2> 23870 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10087 (1428071893893644288)]} 0 15
[junit4:junit4]   2> 23871 T485 C2 P32543 /update {wt=javabin&version=2} {add=[87 (1428071893892595712)]} 0 18
[junit4:junit4]   2> 23875 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[70 (-1428071893914615808)]} 0 1
[junit4:junit4]   2> 23877 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10087 (1428071893914615808)]} 0 2
[junit4:junit4]   2> 23882 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[10070 (-1428071893921955840)]} 0 0
[junit4:junit4]   2> 23883 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[70 (-1428071893923004416)]} 0 0
[junit4:junit4]   2> 23886 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10070 (-1428071893926150144)]} 0 1
[junit4:junit4]   2> 23906 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10088 (1428071893929295872)]} 0 17
[junit4:junit4]   2> 23906 T464 C1 P32516 /update {wt=javabin&version=2} {add=[88 (1428071893926150144)]} 0 20
[junit4:junit4]   2> 23916 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10088 (1428071893952364545)]} 0 6
[junit4:junit4]   2> 23920 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10073 (-1428071893961801728)]} 0 1
[junit4:junit4]   2> 23924 T485 C2 P32543 /update {wt=javabin&version=2} {add=[88 (1428071893952364544)]} 0 14
[junit4:junit4]   2> 23924 T484 C2 P32543 /update {wt=javabin&version=2} {delete=[10073 (-1428071893964947456)]} 0 1
[junit4:junit4]   2> 23927 T464 C1 P32516 /update {wt=javabin&version=2} {delete=[73 (-1428071893969141760)]} 0 1
[junit4:junit4]   2> 23930 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[73 (-1428071893972287488)]} 0 0
[junit4:junit4]   2> 23936 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10089 (1428071893968093184)]} 0 10
[junit4:junit4]   2> 23937 T464 C1 P32516 /update {wt=javabin&version=2} {add=[89 (1428071893975433216)]} 0 4
[junit4:junit4]   2> 23955 T484 C2 P32543 /update {wt=javabin&version=2} {add=[89 (1428071893981724672)]} 0 16
[junit4:junit4]   2> 23955 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10089 (1428071893981724673)]} 0 16
[junit4:junit4]   2> 23968 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10090 (1428071894003744768)]} 0 9
[junit4:junit4]   2> 23968 T464 C1 P32516 /update {wt=javabin&version=2} {add=[90 (1428071894003744769)]} 0 9
[junit4:junit4]   2> 23978 T484 C2 P32543 /update {wt=javabin&version=2} {add=[10090 (1428071894017376257)]} 0 6
[junit4:junit4]   2> 23995 T485 C2 P32543 /update {wt=javabin&version=2} {add=[90 (1428071894017376256)]} 0 23
[junit4:junit4]   2> 23996 T464 C1 P32516 /update {wt=javabin&version=2} {add=[10091 (1428071894028910592)]} 0 13
[junit4:junit4]   2> 24007 T465 C1 P32516 /update {wt=javabin&version=2} {add=[91 (1428071894045687808)]} 0 8
[junit4:junit4]   2> 24007 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10091 (1428071894045687808)]} 0 8
[junit4:junit4]   2> 24011 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[10074 (-1428071894057222144)]} 0 1
[junit4:junit4]   2> 24012 T484 C2 P32543 /update {wt=javabin&version=2} {add=[91 (1428071894057222144)]} 0 2
[junit4:junit4]   2> 24015 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[10074 (-1428071894060367872)]} 0 1
[junit4:junit4]   2> 24015 T465 C1 P32516 /update {wt=javabin&version=2} {delete=[74 (-1428071894061416448)]} 0 1
[junit4:junit4]   2> 24019 T485 C2 P32543 /update {wt=javabin&version=2} {delete=[74 (-1428071894065610752)]} 0 1
[junit4:junit4]   2> 24020 T465 C1 P32516 /update {wt=javabin&version=2} {add=[10092 (1428071894065610752)]} 0 2
[junit4:junit4]   2> 24026 T464 C1 P32516 /update {wt=javabin&version=2} {add=[92 (1428071894071902208)]} 0 2
[junit4:junit4]   2> 24029 T485 C2 P32543 /update {wt=javabin&version=2} {add=[10092 (1428071894075047936)]} 0 2
[junit4:junit4]   2> 24032 T484 C2 P32543 /update {wt=javabin&version=

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

ry:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/index.20130227035139646
[junit4:junit4]   2> 81116 T531 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2/index.20130227035139646
[junit4:junit4]   2> 81459 T450 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4]   2> 81829 T531 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2
[junit4:junit4]   2> 81829 T531 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.RecoveryZkTest-1361915463391/jetty2
[junit4:junit4]   2> 81830 T531 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> 81830 T531 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 81830 T531 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 81830 T531 oasc.LeaderElector$1.process WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:236)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:233)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:233)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   2> 
[junit4:junit4]   2> 81831 T531 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   1> coreNodeName:3
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_l=Pulsing41(freqCutoff=12 minBlockSize=91 maxBlockSize=262), text=PostingsFormat(name=MockRandom), _version_=Pulsing41(freqCutoff=12 minBlockSize=91 maxBlockSize=262), rnd_b=PostingsFormat(name=TestBloomFilteredLucene41Postings), intDefault=Pulsing41(freqCutoff=12 minBlockSize=91 maxBlockSize=262), id=PostingsFormat(name=TestBloomFilteredLucene41Postings), timestamp=Pulsing41(freqCutoff=12 minBlockSize=91 maxBlockSize=262), a_t=Pulsing41(freqCutoff=12 minBlockSize=91 maxBlockSize=262), range_facet_sl=PostingsFormat(name=MockRandom), range_facet_si=PostingsFormat(name=Memory doPackFST= true), other_tl1=Pulsing41(freqCutoff=12 minBlockSize=91 maxBlockSize=262), multiDefault=PostingsFormat(name=Memory doPackFST= true), a_si=PostingsFormat(name=Memory doPackFST= true)}, docValues:{}, sim=DefaultSimilarity, locale=lt_LT, timezone=Asia/Dhaka
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=308734768,total=451346432
[junit4:junit4]   2> NOTE: All tests run in this JVM: [OverseerTest, RecoveryZkTest]
[junit4:junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RecoveryZkTest -Dtests.seed=561ABA8D077A85ED -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=lt_LT -Dtests.timezone=Asia/Dhaka -Dtests.file.encoding=ISO8859-1
[junit4:junit4] ERROR   0.00s J1 | RecoveryZkTest (suite) <<<
[junit4:junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=532, name=coreLoadExecutor-118-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([561ABA8D077A85ED]: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:520)
[junit4:junit4]    > 	at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:980)
[junit4:junit4]    > 	at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:878)
[junit4:junit4]    > 	at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:870)
[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:244)
[junit4:junit4]    > 	at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:458)
[junit4:junit4]    > 	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:730)
[junit4:junit4]    > 	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:619)
[junit4:junit4]    > 	at org.apache.solr.core.CoreContainer.createFromZk(CoreContainer.java:967)
[junit4:junit4]    > 	at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1049)
[junit4:junit4]    > 	at org.apache.solr.core.CoreContainer$3.call(CoreContainer.java:634)
[junit4:junit4]    > 	at org.apache.solr.core.CoreContainer$3.call(CoreContainer.java:629)
[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@2745240a lockFactory=org.apache.lucene.store.NativeFSLockFactory@67c78f98)
[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 J1 in 83.08s, 1 test, 1 error <<< FAILURES!

[...truncated 797 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:388: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:361: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:183: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1202: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:865: There were test failures: 257 suites, 1074 tests, 1 suite-level error, 22 ignored (4 assumptions)

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