You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/03/11 12:29:34 UTC
[JENKINS] Lucene-Solr-4.x-Linux
(32bit/jrockit-jdk1.6.0_33-R28.2.4-4.1.0) - Build # 4632 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/4632/
Java: 32bit/jrockit-jdk1.6.0_33-R28.2.4-4.1.0 -XnoOpt
2 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=2967, name=coreLoadExecutor-1918-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=2967, name=coreLoadExecutor-1918-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
at java.lang.Thread.getStackTrace(Thread.java:1479)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:520)
at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:986)
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:34)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:272)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:224)
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:744)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:619)
at org.apache.solr.core.CoreContainer.createFromZk(CoreContainer.java:874)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:957)
at org.apache.solr.core.CoreContainer$2.call(CoreContainer.java:580)
at org.apache.solr.core.CoreContainer$2.call(CoreContainer.java:575)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aec7bbd lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aec828c)
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:616)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
... 1 more
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=2969, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
Stack Trace:
com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=2969, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
at java.lang.Thread.getStackTrace(Thread.java:1479)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:520)
at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:986)
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:34)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:272)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:224)
at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:383)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:281)
at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:153)
at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:409)
at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:223)
Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aefa9fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aefaf46)
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:616)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 8725 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4] 2> 0 T2908 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_ymk/
[junit4:junit4] 2> 20 T2908 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-RecoveryZkTest-1363000894497
[junit4:junit4] 2> 21 T2908 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 21 T2909 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 22 T2909 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 22 T2909 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 23 T2909 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 23 T2909 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 23 T2909 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1363000894497/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 122 T2908 oasc.ZkTestServer.run start zk server on port:59738
[junit4:junit4] 2> 122 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b8a30be
[junit4:junit4] 2> 123 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 123 T2914 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 123 T2914 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 123 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39047
[junit4:junit4] 2> 124 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39047
[junit4:junit4] 2> 124 T2912 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 451 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240000 with negotiated timeout 10000 for client /127.0.0.1:39047
[junit4:junit4] 2> 452 T2914 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240000, negotiated timeout = 10000
[junit4:junit4] 2> 452 T2915 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b8a30be name:ZooKeeperConnection Watcher:127.0.0.1:59738 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 452 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 453 T2908 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 454 T2913 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d592f24240000
[junit4:junit4] 2> 455 T2915 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 455 T2908 oaz.ZooKeeper.close Session: 0x13d592f24240000 closed
[junit4:junit4] 2> 455 T2910 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39047 which had sessionid 0x13d592f24240000
[junit4:junit4] 2> 455 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1bab0046
[junit4:junit4] 2> 456 T2916 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 456 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 457 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39050
[junit4:junit4] 2> 457 T2916 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 457 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39050
[junit4:junit4] 2> 458 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240001 with negotiated timeout 10000 for client /127.0.0.1:39050
[junit4:junit4] 2> 458 T2916 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240001, negotiated timeout = 10000
[junit4:junit4] 2> 458 T2917 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bab0046 name:ZooKeeperConnection Watcher:127.0.0.1:59738/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 458 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 459 T2908 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 461 T2908 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 463 T2908 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 464 T2908 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 466 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 466 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 469 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 470 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 473 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 473 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 475 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 476 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 478 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 478 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 480 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 480 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 483 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 483 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 488 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 488 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 490 T2908 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 491 T2908 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 494 T2913 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d592f24240001
[junit4:junit4] 2> 495 T2917 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 495 T2908 oaz.ZooKeeper.close Session: 0x13d592f24240001 closed
[junit4:junit4] 2> 495 T2910 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39050 which had sessionid 0x13d592f24240001
[junit4:junit4] 2> 576 T2908 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 587 T2908 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60104
[junit4:junit4] 2> 587 T2908 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 588 T2908 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 588 T2908 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971
[junit4:junit4] 2> 589 T2908 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971/solr.xml
[junit4:junit4] 2> 589 T2908 oasc.CoreContainer.<init> New CoreContainer 464568377
[junit4:junit4] 2> 590 T2908 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971/'
[junit4:junit4] 2> 590 T2908 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971/'
[junit4:junit4] 2> 611 T2908 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 611 T2908 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 612 T2908 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 612 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 612 T2908 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 613 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 613 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 613 T2908 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 614 T2908 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 614 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 623 T2908 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 639 T2908 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:59738/solr
[junit4:junit4] 2> 640 T2908 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 640 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1bb97a73
[junit4:junit4] 2> 641 T2927 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 641 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 641 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39051
[junit4:junit4] 2> 641 T2927 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 645 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39051
[junit4:junit4] 2> 646 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240002 with negotiated timeout 20000 for client /127.0.0.1:39051
[junit4:junit4] 2> 646 T2927 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240002, negotiated timeout = 20000
[junit4:junit4] 2> 646 T2928 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bb97a73 name:ZooKeeperConnection Watcher:127.0.0.1:59738 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 647 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 648 T2913 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d592f24240002
[junit4:junit4] 2> 648 T2910 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39051 which had sessionid 0x13d592f24240002
[junit4:junit4] 2> 649 T2908 oaz.ZooKeeper.close Session: 0x13d592f24240002 closed
[junit4:junit4] 2> 650 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 653 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1bba8f0b
[junit4:junit4] 2> 650 T2928 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 654 T2929 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 655 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 655 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39052
[junit4:junit4] 2> 655 T2929 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 661 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39052
[junit4:junit4] 2> 662 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240003 with negotiated timeout 20000 for client /127.0.0.1:39052
[junit4:junit4] 2> 662 T2929 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240003, negotiated timeout = 20000
[junit4:junit4] 2> 662 T2930 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bba8f0b name:ZooKeeperConnection Watcher:127.0.0.1:59738/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 663 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 664 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 665 T2908 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 666 T2908 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60104__ymk
[junit4:junit4] 2> 666 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:60104__ymk Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:60104__ymk
[junit4:junit4] 2> 667 T2908 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60104__ymk
[junit4:junit4] 2> 669 T2908 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 672 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 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> 673 T2908 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 675 T2908 oasc.Overseer.start Overseer (id=89325626621952003-127.0.0.1:60104__ymk-n_0000000000) starting
[junit4:junit4] 2> 675 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 676 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 676 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 677 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 678 T2932 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 678 T2908 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 680 T2908 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 681 T2908 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 685 T2931 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 688 T2933 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971/collection1
[junit4:junit4] 2> 688 T2933 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 689 T2933 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 689 T2933 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 690 T2933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971/collection1/'
[junit4:junit4] 2> 690 T2933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971/collection1/lib/README' to classloader
[junit4:junit4] 2> 691 T2933 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 726 T2933 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4] 2> 776 T2933 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 777 T2933 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 783 T2933 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1340 T2933 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1347 T2933 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1351 T2933 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1361 T2933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1364 T2933 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1368 T2933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1369 T2933 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1369 T2933 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1369 T2933 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1370 T2933 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1370 T2933 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1371 T2933 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1371 T2933 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1363000894971/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/control/data/
[junit4:junit4] 2> 1371 T2933 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aba6950
[junit4:junit4] 2> 1371 T2933 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1372 T2933 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1363000894497/control/data forceNew: false
[junit4:junit4] 2> 1372 T2933 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/control/data/index/
[junit4:junit4] 2> 1372 T2933 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1363000894497/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1372 T2933 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1363000894497/control/data/index forceNew: false
[junit4:junit4] 2> 1374 T2933 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1ae7ed45 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ae7f335),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1374 T2933 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1375 T2933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1375 T2933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1376 T2933 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1376 T2933 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1377 T2933 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1377 T2933 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1377 T2933 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1377 T2933 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1378 T2933 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1380 T2933 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1383 T2933 oass.SolrIndexSearcher.<init> Opening Searcher@1b127d3d main
[junit4:junit4] 2> 1383 T2933 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/control/data/tlog
[junit4:junit4] 2> 1383 T2933 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1384 T2933 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1388 T2934 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b127d3d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1390 T2933 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1390 T2933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1391 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x55 zxid:0x2a txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 2188 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2189 T2931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[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:60104__ymk",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60104/_ymk"}
[junit4:junit4] 2> 2189 T2931 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2189 T2931 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 2190 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x5d zxid:0x2d txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 2193 T2930 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> 2393 T2933 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2393 T2933 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60104/_ymk collection:control_collection shard:shard1
[junit4:junit4] 2> 2394 T2933 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2399 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:delete cxid:0x77 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 2399 T2933 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2399 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x78 zxid:0x38 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2400 T2933 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2401 T2933 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2401 T2933 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60104/_ymk/collection1/
[junit4:junit4] 2> 2401 T2933 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2401 T2933 oasc.SyncStrategy.syncToMe http://127.0.0.1:60104/_ymk/collection1/ has no replicas
[junit4:junit4] 2> 2401 T2933 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60104/_ymk/collection1/
[junit4:junit4] 2> 2402 T2933 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2404 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240003 type:create cxid:0x82 zxid:0x3c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3696 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3702 T2930 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> 3709 T2933 oasc.ZkController.register We are http://127.0.0.1:60104/_ymk/collection1/ and leader is http://127.0.0.1:60104/_ymk/collection1/
[junit4:junit4] 2> 3709 T2933 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60104/_ymk
[junit4:junit4] 2> 3710 T2933 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3710 T2933 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3710 T2933 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3711 T2933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3712 T2908 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 3712 T2908 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3713 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3718 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3719 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b1985f6
[junit4:junit4] 2> 3720 T2936 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 3720 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3720 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39059
[junit4:junit4] 2> 3720 T2936 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 3721 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39059
[junit4:junit4] 2> 3721 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240004 with negotiated timeout 10000 for client /127.0.0.1:39059
[junit4:junit4] 2> 3721 T2936 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240004, negotiated timeout = 10000
[junit4:junit4] 2> 3722 T2937 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b1985f6 name:ZooKeeperConnection Watcher:127.0.0.1:59738/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3722 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3723 T2908 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3725 T2908 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 3820 T2908 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 3822 T2908 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44043
[junit4:junit4] 2> 3822 T2908 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 3822 T2908 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3823 T2908 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201
[junit4:junit4] 2> 3823 T2908 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201/solr.xml
[junit4:junit4] 2> 3824 T2908 oasc.CoreContainer.<init> New CoreContainer 455190731
[junit4:junit4] 2> 3824 T2908 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201/'
[junit4:junit4] 2> 3825 T2908 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201/'
[junit4:junit4] 2> 3848 T2908 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 3849 T2908 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 3849 T2908 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 3849 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 3850 T2908 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 3850 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 3851 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 3851 T2908 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 3851 T2908 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3852 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 3862 T2908 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 3881 T2908 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:59738/solr
[junit4:junit4] 2> 3882 T2908 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 3882 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b46fabb
[junit4:junit4] 2> 3883 T2947 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 3883 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3884 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39060
[junit4:junit4] 2> 3883 T2947 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 3884 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39060
[junit4:junit4] 2> 3885 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240005 with negotiated timeout 20000 for client /127.0.0.1:39060
[junit4:junit4] 2> 3885 T2947 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240005, negotiated timeout = 20000
[junit4:junit4] 2> 3885 T2948 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b46fabb name:ZooKeeperConnection Watcher:127.0.0.1:59738 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3885 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3886 T2913 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d592f24240005
[junit4:junit4] 2> 3886 T2948 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 3886 T2908 oaz.ZooKeeper.close Session: 0x13d592f24240005 closed
[junit4:junit4] 2> 3886 T2910 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39060 which had sessionid 0x13d592f24240005
[junit4:junit4] 2> 3887 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 3890 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b47f065
[junit4:junit4] 2> 3891 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3891 T2949 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 3892 T2949 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 3892 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39061
[junit4:junit4] 2> 3892 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39061
[junit4:junit4] 2> 3893 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240006 with negotiated timeout 20000 for client /127.0.0.1:39061
[junit4:junit4] 2> 3893 T2949 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240006, negotiated timeout = 20000
[junit4:junit4] 2> 3893 T2950 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b47f065 name:ZooKeeperConnection Watcher:127.0.0.1:59738/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3893 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3894 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240006 type:create cxid:0x1 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3894 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240006 type:create cxid:0x2 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3895 T2908 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4897 T2908 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44043__ymk
[junit4:junit4] 2> 4898 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240006 type:delete cxid:0xb zxid:0x4c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:44043__ymk Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:44043__ymk
[junit4:junit4] 2> 4899 T2908 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44043__ymk
[junit4:junit4] 2> 4900 T2950 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4901 T2937 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4900 T2930 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4901 T2930 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> 4906 T2951 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201/collection1
[junit4:junit4] 2> 4906 T2951 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 4907 T2951 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 4907 T2951 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 4908 T2951 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201/collection1/'
[junit4:junit4] 2> 4908 T2951 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201/collection1/lib/README' to classloader
[junit4:junit4] 2> 4908 T2951 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 4946 T2951 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4] 2> 4998 T2951 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 4999 T2951 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 5005 T2951 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 5228 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5229 T2931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[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:60104__ymk",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:60104/_ymk"}
[junit4:junit4] 2> 5231 T2950 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> 5231 T2930 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> 5231 T2937 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> 5541 T2951 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 5548 T2951 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5551 T2951 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5568 T2951 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5572 T2951 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5576 T2951 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5578 T2951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5578 T2951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5579 T2951 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5580 T2951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5581 T2951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5581 T2951 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5581 T2951 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1363000898201/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty1/
[junit4:junit4] 2> 5582 T2951 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aba6950
[junit4:junit4] 2> 5582 T2951 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5583 T2951 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty1 forceNew: false
[junit4:junit4] 2> 5583 T2951 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty1/index/
[junit4:junit4] 2> 5583 T2951 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5584 T2951 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty1/index forceNew: false
[junit4:junit4] 2> 5585 T2951 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1b3141da lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b3147ca),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 5586 T2951 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 5588 T2951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 5588 T2951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 5588 T2951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 5589 T2951 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 5590 T2951 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 5590 T2951 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 5591 T2951 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 5592 T2951 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 5592 T2951 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 5595 T2951 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 5599 T2951 oass.SolrIndexSearcher.<init> Opening Searcher@1b39140d main
[junit4:junit4] 2> 5599 T2951 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty1/tlog
[junit4:junit4] 2> 5600 T2951 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 5600 T2951 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 5607 T2952 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b39140d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5610 T2951 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5610 T2951 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6734 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6734 T2931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[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:44043__ymk",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44043/_ymk"}
[junit4:junit4] 2> 6735 T2931 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 6735 T2931 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 6737 T2930 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> 6737 T2937 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> 6737 T2950 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> 7611 T2951 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7612 T2951 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44043/_ymk collection:collection1 shard:shard1
[junit4:junit4] 2> 7613 T2951 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 7618 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240006 type:delete cxid:0x48 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 7618 T2951 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7619 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240006 type:create cxid:0x49 zxid:0x5d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7620 T2951 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7621 T2951 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7621 T2951 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44043/_ymk/collection1/
[junit4:junit4] 2> 7621 T2951 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7622 T2951 oasc.SyncStrategy.syncToMe http://127.0.0.1:44043/_ymk/collection1/ has no replicas
[junit4:junit4] 2> 7622 T2951 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44043/_ymk/collection1/
[junit4:junit4] 2> 7622 T2951 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 7625 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240006 type:create cxid:0x53 zxid:0x61 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8241 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8247 T2930 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> 8247 T2950 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> 8247 T2937 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> 8278 T2951 oasc.ZkController.register We are http://127.0.0.1:44043/_ymk/collection1/ and leader is http://127.0.0.1:44043/_ymk/collection1/
[junit4:junit4] 2> 8278 T2951 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44043/_ymk
[junit4:junit4] 2> 8278 T2951 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8278 T2951 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8279 T2951 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8280 T2951 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8281 T2908 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 8281 T2908 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8282 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8347 T2908 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8349 T2908 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49292
[junit4:junit4] 2> 8350 T2908 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8350 T2908 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8350 T2908 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761
[junit4:junit4] 2> 8351 T2908 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761/solr.xml
[junit4:junit4] 2> 8351 T2908 oasc.CoreContainer.<init> New CoreContainer 458143353
[junit4:junit4] 2> 8352 T2908 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761/'
[junit4:junit4] 2> 8352 T2908 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761/'
[junit4:junit4] 2> 8370 T2908 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8371 T2908 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8371 T2908 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8372 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8372 T2908 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8372 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8372 T2908 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8373 T2908 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8373 T2908 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8373 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8382 T2908 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8397 T2908 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:59738/solr
[junit4:junit4] 2> 8397 T2908 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8398 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b457695
[junit4:junit4] 2> 8399 T2963 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8399 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8399 T2963 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 8399 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39065
[junit4:junit4] 2> 8399 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39065
[junit4:junit4] 2> 8400 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240007 with negotiated timeout 20000 for client /127.0.0.1:39065
[junit4:junit4] 2> 8400 T2963 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240007, negotiated timeout = 20000
[junit4:junit4] 2> 8401 T2964 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b457695 name:ZooKeeperConnection Watcher:127.0.0.1:59738 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8401 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8401 T2913 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d592f24240007
[junit4:junit4] 2> 8402 T2964 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8402 T2910 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39065 which had sessionid 0x13d592f24240007
[junit4:junit4] 2> 8402 T2908 oaz.ZooKeeper.close Session: 0x13d592f24240007 closed
[junit4:junit4] 2> 8403 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8405 T2908 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:59738/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b46e833
[junit4:junit4] 2> 8406 T2965 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:59738. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8406 T2908 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8407 T2910 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:39066
[junit4:junit4] 2> 8407 T2965 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:59738, initiating session
[junit4:junit4] 2> 8407 T2910 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:39066
[junit4:junit4] 2> 8408 T2912 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d592f24240008 with negotiated timeout 20000 for client /127.0.0.1:39066
[junit4:junit4] 2> 8408 T2965 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:59738, sessionid = 0x13d592f24240008, negotiated timeout = 20000
[junit4:junit4] 2> 8408 T2966 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b46e833 name:ZooKeeperConnection Watcher:127.0.0.1:59738/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8408 T2908 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8409 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240008 type:create cxid:0x1 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8410 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240008 type:create cxid:0x2 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8411 T2908 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9413 T2908 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49292__ymk
[junit4:junit4] 2> 9414 T2913 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d592f24240008 type:delete cxid:0xb zxid:0x70 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49292__ymk Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49292__ymk
[junit4:junit4] 2> 9414 T2908 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49292__ymk
[junit4:junit4] 2> 9416 T2950 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> 9416 T2937 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9417 T2937 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> 9417 T2930 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9417 T2966 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9417 T2930 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> 9417 T2950 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9426 T2967 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761/collection1
[junit4:junit4] 2> 9426 T2967 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9427 T2967 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9427 T2967 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9428 T2967 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761/collection1/'
[junit4:junit4] 2> 9428 T2967 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761/collection1/lib/README' to classloader
[junit4:junit4] 2> 9428 T2967 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9467 T2967 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4] 2> 9514 T2967 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9515 T2967 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9520 T2967 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9753 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9754 T2931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[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:44043__ymk",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44043/_ymk"}
[junit4:junit4] 2> 9762 T2937 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> 9762 T2966 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> 9762 T2930 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> 9762 T2950 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> 10049 T2967 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10057 T2967 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10060 T2967 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10071 T2967 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10075 T2967 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10078 T2967 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10079 T2967 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10079 T2967 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10080 T2967 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10080 T2967 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10081 T2967 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10081 T2967 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10081 T2967 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1363000902761/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/
[junit4:junit4] 2> 10081 T2967 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aba6950
[junit4:junit4] 2> 10082 T2967 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10082 T2967 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2 forceNew: false
[junit4:junit4] 2> 10082 T2967 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/index/
[junit4:junit4] 2> 10082 T2967 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10083 T2967 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/index forceNew: false
[junit4:junit4] 2> 10084 T2967 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1aecab67 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aecb157),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10084 T2967 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10085 T2967 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10086 T2967 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10086 T2967 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10087 T2967 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10087 T2967 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10087 T2967 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10088 T2967 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10088 T2967 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10088 T2967 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10090 T2967 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10093 T2967 oass.SolrIndexSearcher.<init> Opening Searcher@1b0b02df main
[junit4:junit4] 2> 10094 T2967 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/tlog
[junit4:junit4] 2> 10094 T2967 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10094 T2967 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10101 T2968 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b0b02df main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10104 T2967 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10105 T2967 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11266 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11267 T2931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[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:49292__ymk",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49292/_ymk"}
[junit4:junit4] 2> 11267 T2931 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 11267 T2931 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 11271 T2950 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> 11271 T2930 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> 11271 T2937 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> 11271 T2966 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> 12106 T2967 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 12106 T2967 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49292/_ymk collection:collection1 shard:shard1
[junit4:junit4] 2> 12109 T2967 oasc.ZkController.register We are http://127.0.0.1:49292/_ymk/collection1/ and leader is http://127.0.0.1:44043/_ymk/collection1/
[junit4:junit4] 2> 12109 T2967 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49292/_ymk
[junit4:junit4] 2> 12109 T2967 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 12109 T2967 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C361 name=collection1 org.apache.solr.core.SolrCore@1aec30f1 url=http://127.0.0.1:49292/_ymk/collection1 node=127.0.0.1:49292__ymk C361_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:49292__ymk, base_url=http://127.0.0.1:49292/_ymk}
[junit4:junit4] 2> 12110 T2969 C361 P49292 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 12110 T2969 C361 P49292 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 12110 T2967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12110 T2969 C361 P49292 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 12110 T2969 C361 P49292 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12111 T2908 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 12111 T2908 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 12112 T2908 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 12115 T2969 C361 P49292 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 12115 T2908 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C362 name=collection1 org.apache.solr.core.SolrCore@1ae7766a url=http://127.0.0.1:60104/_ymk/collection1 node=127.0.0.1:60104__ymk C362_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:60104__ymk, base_url=http://127.0.0.1:60104/_ymk, leader=true}
[junit4:junit4] 2> 12127 T2923 C362 P60104 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1ae7ed45 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ae7f335),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 12127 T2923 C362 P60104 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 12128 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[1 (1429210038641098752)]} 0 2
[junit4:junit4] 2> 12128 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10001 (1429210038641098753)]} 0 2
[junit4:junit4] 2> ASYNC NEW_CORE C363 name=collection1 org.apache.solr.core.SolrCore@1b1c8421 url=http://127.0.0.1:44043/_ymk/collection1 node=127.0.0.1:44043__ymk C363_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:44043__ymk, base_url=http://127.0.0.1:44043/_ymk, leader=true}
[junit4:junit4] 2> 12139 T2944 C363 P44043 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1b3141da lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b3147ca),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 12140 T2944 C363 P44043 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 12141 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10001 (1429210038653681664)]} 0 3
[junit4:junit4] 2> 12141 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[1 (1429210038653681665)]} 0 3
[junit4:junit4] 2> 12231 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10002 (1429210038751199233)]} 0 0
[junit4:junit4] 2> 12232 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[2 (1429210038751199232)]} 0 1
[junit4:junit4] 2> 12234 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10002 (1429210038754344960)]} 0 1
[junit4:junit4] 2> 12234 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[2 (1429210038754344961)]} 0 0
[junit4:junit4] 2> 12244 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[2 (-1429210038763782144)]} 0 1
[junit4:junit4] 2> 12244 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[10002 (-1429210038763782145)]} 0 1
[junit4:junit4] 2> 12246 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[2 (-1429210038766927872)]} 0 1
[junit4:junit4] 2> 12246 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[10002 (-1429210038766927873)]} 0 0
[junit4:junit4] 2> 12248 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[3 (1429210038767976448)]} 0 1
[junit4:junit4] 2> 12248 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10003 (1429210038769025024)]} 0 1
[junit4:junit4] 2> 12250 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[3 (1429210038771122176)]} 0 0
[junit4:junit4] 2> 12250 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10003 (1429210038771122177)]} 0 0
[junit4:junit4] 2> 12337 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[3 (-1429210038862348289)]} 0 1
[junit4:junit4] 2> 12337 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[10003 (-1429210038862348288)]} 0 1
[junit4:junit4] 2> 12339 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[3 (-1429210038864445440)]} 0 0
[junit4:junit4] 2> 12339 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[10003 (-1429210038864445441)]} 0 0
[junit4:junit4] 2> 12341 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[4 (1429210038866542592)]} 0 0
[junit4:junit4] 2> 12341 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10004 (1429210038866542593)]} 0 0
[junit4:junit4] 2> 12343 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[4 (1429210038868639744)]} 0 0
[junit4:junit4] 2> 12344 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10004 (1429210038868639745)]} 0 1
[junit4:junit4] 2> 12412 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[4 (-1429210038940991489)]} 0 0
[junit4:junit4] 2> 12412 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[10004 (-1429210038940991488)]} 0 0
[junit4:junit4] 2> 12414 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[4 (-1429210038943088640)]} 0 0
[junit4:junit4] 2> 12414 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10004 (-1429210038943088641)]} 0 0
[junit4:junit4] 2> 12416 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[5 (1429210038945185792)]} 0 0
[junit4:junit4] 2> 12417 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10005 (1429210038945185793)]} 0 1
[junit4:junit4] 2> 12419 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[5 (1429210038947282944)]} 0 1
[junit4:junit4] 2> 12419 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10005 (1429210038948331520)]} 0 0
[junit4:junit4] 2> 12432 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[6 (1429210038960914432)]} 0 1
[junit4:junit4] 2> 12432 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10006 (1429210038960914433)]} 0 1
[junit4:junit4] 2> 12435 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[6 (1429210038964060160)]} 0 1
[junit4:junit4] 2> 12435 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10006 (1429210038964060161)]} 0 1
[junit4:junit4] 2> 12482 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10005 (-1429210039014391809)]} 0 0
[junit4:junit4] 2> 12482 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[5 (-1429210039014391808)]} 0 0
[junit4:junit4] 2> 12484 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[10005 (-1429210039016488960)]} 0 0
[junit4:junit4] 2> 12484 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[5 (-1429210039016488961)]} 0 0
[junit4:junit4] 2> 12487 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[7 (1429210039018586113)]} 0 1
[junit4:junit4] 2> 12487 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10007 (1429210039018586112)]} 0 1
[junit4:junit4] 2> 12489 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[7 (1429210039021731840)]} 0 0
[junit4:junit4] 2> 12489 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10007 (1429210039021731841)]} 0 0
[junit4:junit4] 2> 12584 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[8 (1429210039120297984)]} 0 1
[junit4:junit4] 2> 12584 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10008 (1429210039120297985)]} 0 1
[junit4:junit4] 2> 12586 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[8 (1429210039123443712)]} 0 0
[junit4:junit4] 2> 12586 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10008 (1429210039123443713)]} 0 0
[junit4:junit4] 2> 12662 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[10006 (-1429210039203135489)]} 0 0
[junit4:junit4] 2> 12662 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[6 (-1429210039203135488)]} 0 0
[junit4:junit4] 2> 12664 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[10006 (-1429210039205232640)]} 0 0
[junit4:junit4] 2> 12664 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[6 (-1429210039205232641)]} 0 0
[junit4:junit4] 2> 12666 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10009 (1429210039207329792)]} 0 0
[junit4:junit4] 2> 12666 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[9 (1429210039207329793)]} 0 0
[junit4:junit4] 2> 12668 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10009 (1429210039209426944)]} 0 0
[junit4:junit4] 2> 12668 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[9 (1429210039209426945)]} 0 0
[junit4:junit4] 2> 12750 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10 (1429210039295410177)]} 0 0
[junit4:junit4] 2> 12750 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10010 (1429210039295410176)]} 0 0
[junit4:junit4] 2> 12753 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10 (1429210039297507328)]} 0 1
[junit4:junit4] 2> 12753 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10010 (1429210039297507329)]} 0 1
[junit4:junit4] 2> 12775 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12776 T2931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[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:49292__ymk",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49292/_ymk"}
[junit4:junit4] 2> 12778 T2937 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> 12778 T2930 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> 12778 T2950 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> 12778 T2966 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> 12821 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[8 (-1429210039369859072)]} 0 0
[junit4:junit4] 2> 12821 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[10008 (-1429210039369859073)]} 0 0
[junit4:junit4] 2> C361_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:49292__ymk, base_url=http://127.0.0.1:49292/_ymk}
[junit4:junit4] 2> 12835 T2961 C361 P49292 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1aecab67 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aecb157),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 12836 T2961 C361 P49292 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 12836 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[8 (-1429210039373004800)]} 0 2
[junit4:junit4] 2> 12836 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10008 (-1429210039373004801)]} 0 1
[junit4:junit4] 2> 12837 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[8 (-1429210039373004800)]} 0 13
[junit4:junit4] 2> 12837 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[10008 (-1429210039373004801)]} 0 13
[junit4:junit4] 2> 12839 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[11 (1429210039388733440)]} 0 0
[junit4:junit4] 2> 12839 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10011 (1429210039388733441)]} 0 0
[junit4:junit4] 2> 12844 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10011 (1429210039390830593)]} 0 1
[junit4:junit4] 2> 12844 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1429210039390830592)]} 0 1
[junit4:junit4] 2> 12844 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10011 (1429210039390830593)]} 0 3
[junit4:junit4] 2> 12844 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[11 (1429210039390830592)]} 0 3
[junit4:junit4] 2> 12918 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10012 (1429210039470522368)]} 0 1
[junit4:junit4] 2> 12919 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[12 (1429210039471570944)]} 0 2
[junit4:junit4] 2> 12924 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10012 (1429210039474716672)]} 0 0
[junit4:junit4] 2> 12925 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1429210039474716673)]} 0 1
[junit4:junit4] 2> 12925 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10012 (1429210039474716672)]} 0 4
[junit4:junit4] 2> 12926 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[12 (1429210039474716673)]} 0 5
[junit4:junit4] 2> 12991 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[10010 (-1429210039548116992)]} 0 0
[junit4:junit4] 2> 12992 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[10 (-1429210039549165568)]} 0 0
[junit4:junit4] 2> 12996 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10010 (-1429210039551262720)]} 0 0
[junit4:junit4] 2> 12996 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10 (-1429210039551262721)]} 0 0
[junit4:junit4] 2> 12997 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10010 (-1429210039551262720)]} 0 3
[junit4:junit4] 2> 12997 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[10 (-1429210039551262721)]} 0 3
[junit4:junit4] 2> 13000 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10013 (1429210039556505600)]} 0 1
[junit4:junit4] 2> 13001 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[13 (1429210039557554176)]} 0 2
[junit4:junit4] 2> 13006 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10013 (1429210039560699904)]} 0 1
[junit4:junit4] 2> 13006 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1429210039560699905)]} 0 1
[junit4:junit4] 2> 13007 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10013 (1429210039560699904)]} 0 5
[junit4:junit4] 2> 13007 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[13 (1429210039560699905)]} 0 4
[junit4:junit4] 2> 13056 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10014 (1429210039615225856)]} 0 1
[junit4:junit4] 2> 13057 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[14 (1429210039616274432)]} 0 1
[junit4:junit4] 2> 13062 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10014 (1429210039619420160)]} 0 1
[junit4:junit4] 2> 13063 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1429210039619420161)]} 0 1
[junit4:junit4] 2> 13063 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10014 (1429210039619420160)]} 0 4
[junit4:junit4] 2> 13064 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[14 (1429210039619420161)]} 0 5
[junit4:junit4] 2> 13091 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10011 (-1429210039652974592)]} 0 0
[junit4:junit4] 2> 13091 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[11 (-1429210039652974593)]} 0 0
[junit4:junit4] 2> 13096 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10011 (-1429210039656120320)]} 0 0
[junit4:junit4] 2> 13096 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[11 (-1429210039656120321)]} 0 0
[junit4:junit4] 2> 13097 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[10011 (-1429210039656120320)]} 0 3
[junit4:junit4] 2> 13097 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[11 (-1429210039656120321)]} 0 3
[junit4:junit4] 2> 13100 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10015 (1429210039661363200)]} 0 1
[junit4:junit4] 2> 13101 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[15 (1429210039662411776)]} 0 1
[junit4:junit4] 2> 13107 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10015 (1429210039665557504)]} 0 1
[junit4:junit4] 2> 13107 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1429210039666606080)]} 0 1
[junit4:junit4] 2> 13108 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10015 (1429210039665557504)]} 0 5
[junit4:junit4] 2> 13108 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[15 (1429210039666606080)]} 0 4
[junit4:junit4] 2> 13119 T2946 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {coreNodeName=127.0.0.1:49292__ymk_collection1&state=recovering&nodeName=127.0.0.1:49292__ymk&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1000
[junit4:junit4] 2> 13207 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10014 (-1429210039774609408)]} 0 0
[junit4:junit4] 2> 13208 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[14 (-1429210039775657984)]} 0 0
[junit4:junit4] 2> 13211 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10014 (-1429210039776706560)]} 0 0
[junit4:junit4] 2> 13211 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[14 (-1429210039776706561)]} 0 0
[junit4:junit4] 2> 13211 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10014 (-1429210039776706560)]} 0 2
[junit4:junit4] 2> 13212 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[14 (-1429210039776706561)]} 0 3
[junit4:junit4] 2> 13214 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10016 (1429210039780900864)]} 0 1
[junit4:junit4] 2> 13214 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[16 (1429210039780900865)]} 0 1
[junit4:junit4] 2> 13218 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10016 (1429210039784046592)]} 0 0
[junit4:junit4] 2> 13218 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1429210039784046593)]} 0 0
[junit4:junit4] 2> 13218 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10016 (1429210039784046592)]} 0 2
[junit4:junit4] 2> 13219 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[16 (1429210039784046593)]} 0 3
[junit4:junit4] 2> 13268 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10017 (1429210039838572544)]} 0 0
[junit4:junit4] 2> 13269 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[17 (1429210039838572545)]} 0 1
[junit4:junit4] 2> 13274 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10017 (1429210039841718272)]} 0 0
[junit4:junit4] 2> 13275 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[17 (1429210039842766848)]} 0 1
[junit4:junit4] 2> 13275 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10017 (1429210039841718272)]} 0 4
[junit4:junit4] 2> 13276 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[17 (1429210039842766848)]} 0 4
[junit4:junit4] 2> 13342 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10018 (1429210039916167168)]} 0 0
[junit4:junit4] 2> 13343 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[18 (1429210039916167169)]} 0 1
[junit4:junit4] 2> 13348 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10018 (1429210039919312896)]} 0 1
[junit4:junit4] 2> 13349 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1429210039919312897)]} 0 1
[junit4:junit4] 2> 13349 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10018 (1429210039919312896)]} 0 4
[junit4:junit4] 2> 13350 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[18 (1429210039919312897)]} 0 5
[junit4:junit4] 2> 13412 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10018 (-1429210039989567488)]} 0 0
[junit4:junit4] 2> 13412 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[18 (-1429210039989567489)]} 0 0
[junit4:junit4] 2> 13417 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10018 (-1429210039992713216)]} 0 0
[junit4:junit4] 2> 13417 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[18 (-1429210039992713217)]} 0 0
[junit4:junit4] 2> 13418 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10018 (-1429210039992713216)]} 0 3
[junit4:junit4] 2> 13418 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[18 (-1429210039992713217)]} 0 3
[junit4:junit4] 2> 13421 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10019 (1429210039999004672)]} 0 1
[junit4:junit4] 2> 13422 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[19 (1429210039999004673)]} 0 1
[junit4:junit4] 2> 13428 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10019 (1429210040002150400)]} 0 1
[junit4:junit4] 2> 13428 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1429210040003198976)]} 0 1
[junit4:junit4] 2> 13428 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10019 (1429210040002150400)]} 0 4
[junit4:junit4] 2> 13429 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[19 (1429210040003198976)]} 0 4
[junit4:junit4] 2> 13444 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10020 (1429210040022073344)]} 0 1
[junit4:junit4] 2> 13444 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[20 (1429210040023121920)]} 0 1
[junit4:junit4] 2> 13450 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10020 (1429210040025219072)]} 0 1
[junit4:junit4] 2> 13450 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1429210040026267648)]} 0 1
[junit4:junit4] 2> 13451 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10020 (1429210040025219072)]} 0 5
[junit4:junit4] 2> 13451 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[20 (1429210040026267648)]} 0 4
[junit4:junit4] 2> 13518 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[10019 (-1429210040100716544)]} 0 0
[junit4:junit4] 2> 13518 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[19 (-1429210040100716545)]} 0 0
[junit4:junit4] 2> 13522 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10019 (-1429210040102813696)]} 0 0
[junit4:junit4] 2> 13522 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[19 (-1429210040103862272)]} 0 0
[junit4:junit4] 2> 13523 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[10019 (-1429210040102813696)]} 0 3
[junit4:junit4] 2> 13523 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[19 (-1429210040103862272)]} 0 3
[junit4:junit4] 2> 13526 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10021 (1429210040108056576)]} 0 1
[junit4:junit4] 2> 13526 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[21 (1429210040108056577)]} 0 1
[junit4:junit4] 2> 13532 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10021 (1429210040112250880)]} 0 0
[junit4:junit4] 2> 13533 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1429210040112250881)]} 0 1
[junit4:junit4] 2> 13533 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10021 (1429210040112250880)]} 0 4
[junit4:junit4] 2> 13534 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[21 (1429210040112250881)]} 0 5
[junit4:junit4] 2> 13616 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[21 (-1429210040203476992)]} 0 1
[junit4:junit4] 2> 13616 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[10021 (-1429210040202428416)]} 0 1
[junit4:junit4] 2> 13620 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[21 (-1429210040205574144)]} 0 0
[junit4:junit4] 2> 13621 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10021 (-1429210040206622720)]} 0 1
[junit4:junit4] 2> 13621 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[21 (-1429210040205574144)]} 0 3
[junit4:junit4] 2> 13621 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10021 (-1429210040206622720)]} 0 2
[junit4:junit4] 2> 13624 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[22 (1429210040210817024)]} 0 1
[junit4:junit4] 2> 13624 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10022 (1429210040210817025)]} 0 1
[junit4:junit4] 2> 13628 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1429210040213962752)]} 0 0
[junit4:junit4] 2> 13628 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[22 (1429210040213962752)]} 0 2
[junit4:junit4] 2> 13629 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10022 (1429210040213962753)]} 0 1
[junit4:junit4] 2> 13629 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10022 (1429210040213962753)]} 0 3
[junit4:junit4] 2> 13729 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[23 (1429210040321966080)]} 0 1
[junit4:junit4] 2> 13730 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10023 (1429210040321966081)]} 0 1
[junit4:junit4] 2> 13733 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1429210040324063232)]} 0 0
[junit4:junit4] 2> 13734 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[23 (1429210040324063232)]} 0 3
[junit4:junit4] 2> 13734 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10023 (1429210040325111808)]} 0 0
[junit4:junit4] 2> 13735 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10023 (1429210040325111808)]} 0 3
[junit4:junit4] 2> 13754 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[24 (1429210040348180480)]} 0 0
[junit4:junit4] 2> 13755 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10024 (1429210040349229056)]} 0 1
[junit4:junit4] 2> 13759 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1429210040351326208)]} 0 1
[junit4:junit4] 2> 13759 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[24 (1429210040351326208)]} 0 2
[junit4:junit4] 2> 13759 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10024 (1429210040351326209)]} 0 0
[junit4:junit4] 2> 13760 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10024 (1429210040351326209)]} 0 3
[junit4:junit4] 2> 13768 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[24 (-1429210040362860544)]} 0 0
[junit4:junit4] 2> 13769 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[10024 (-1429210040363909120)]} 0 0
[junit4:junit4] 2> 13772 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[24 (-1429210040364957696)]} 0 1
[junit4:junit4] 2> 13772 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[24 (-1429210040364957696)]} 0 2
[junit4:junit4] 2> 13773 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10024 (-1429210040366006272)]} 0 1
[junit4:junit4] 2> 13773 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10024 (-1429210040366006272)]} 0 2
[junit4:junit4] 2> 13774 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[25 (1429210040369152000)]} 0 0
[junit4:junit4] 2> 13775 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10025 (1429210040370200576)]} 0 0
[junit4:junit4] 2> 13778 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1429210040371249152)]} 0 0
[junit4:junit4] 2> 13779 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[25 (1429210040371249152)]} 0 3
[junit4:junit4] 2> 13779 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10025 (1429210040372297728)]} 0 0
[junit4:junit4] 2> 13780 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10025 (1429210040372297728)]} 0 3
[junit4:junit4] 2> 13864 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[26 (1429210040463523840)]} 0 0
[junit4:junit4] 2> 13865 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10026 (1429210040464572416)]} 0 0
[junit4:junit4] 2> 13868 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1429210040465620992)]} 0 0
[junit4:junit4] 2> 13869 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[26 (1429210040465620992)]} 0 3
[junit4:junit4] 2> 13869 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10026 (1429210040466669568)]} 0 0
[junit4:junit4] 2> 13870 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10026 (1429210040466669568)]} 0 3
[junit4:junit4] 2> 13899 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[27 (1429210040500224000)]} 0 0
[junit4:junit4] 2> 13900 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10027 (1429210040500224001)]} 0 1
[junit4:junit4] 2> 13904 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1429210040502321152)]} 0 1
[junit4:junit4] 2> 13904 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[27 (1429210040502321152)]} 0 3
[junit4:junit4] 2> 13904 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10027 (1429210040503369728)]} 0 1
[junit4:junit4] 2> 13905 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10027 (1429210040503369728)]} 0 3
[junit4:junit4] 2> 13985 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[28 (1429210040590401536)]} 0 0
[junit4:junit4] 2> 13986 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10028 (1429210040591450112)]} 0 0
[junit4:junit4] 2> 13990 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1429210040592498688)]} 0 1
[junit4:junit4] 2> 13990 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10028 (1429210040593547264)]} 0 0
[junit4:junit4] 2> 13990 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[28 (1429210040592498688)]} 0 3
[junit4:junit4] 2> 13990 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10028 (1429210040593547264)]} 0 2
[junit4:junit4] 2> 14062 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10029 (1429210040670093313)]} 0 1
[junit4:junit4] 2> 14062 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[29 (1429210040670093312)]} 0 1
[junit4:junit4] 2> 14066 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10029 (1429210040673239040)]} 0 1
[junit4:junit4] 2> 14066 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1429210040673239041)]} 0 0
[junit4:junit4] 2> 14066 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10029 (1429210040673239040)]} 0 2
[junit4:junit4] 2> 14067 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[29 (1429210040673239041)]} 0 3
[junit4:junit4] 2> 14095 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10030 (1429210040704696320)]} 0 1
[junit4:junit4] 2> 14095 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[30 (1429210040705744896)]} 0 0
[junit4:junit4] 2> 14099 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10030 (1429210040707842048)]} 0 1
[junit4:junit4] 2> 14099 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1429210040707842049)]} 0 0
[junit4:junit4] 2> 14100 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10030 (1429210040707842048)]} 0 3
[junit4:junit4] 2> 14100 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[30 (1429210040707842049)]} 0 3
[junit4:junit4] 2> 14118 T2908 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 49292
[junit4:junit4] 2> 14119 T2908 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=458143353
[junit4:junit4] 2> 14165 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[10025 (-1429210040779145216)]} 0 0
[junit4:junit4] 2> 14165 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[25 (-1429210040779145217)]} 0 0
[junit4:junit4] 2> 14168 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10025 (-1429210040780193792)]} 0 0
[junit4:junit4] 2> 14168 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[25 (-1429210040781242368)]} 0 0
[junit4:junit4] 2> 14169 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10025 (-1429210040780193792)]} 0 3
[junit4:junit4] 2> 14169 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[25 (-1429210040781242368)]} 0 2
[junit4:junit4] 2> 14171 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10031 (1429210040785436672)]} 0 1
[junit4:junit4] 2> 14171 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[31 (1429210040785436673)]} 0 0
[junit4:junit4] 2> 14175 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10031 (1429210040787533824)]} 0 0
[junit4:junit4] 2> 14175 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1429210040787533825)]} 0 0
[junit4:junit4] 2> 14176 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10031 (1429210040787533824)]} 0 3
[junit4:junit4] 2> 14176 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[31 (1429210040787533825)]} 0 3
[junit4:junit4] 2> 14274 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[10027 (-1429210040893440000)]} 0 0
[junit4:junit4] 2> 14274 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[27 (-1429210040893440001)]} 0 0
[junit4:junit4] 2> 14277 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[27 (-1429210040895537153)]} 0 0
[junit4:junit4] 2> 14277 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10027 (-1429210040895537152)]} 0 0
[junit4:junit4] 2> 14278 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[27 (-1429210040895537153)]} 0 2
[junit4:junit4] 2> 14278 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10027 (-1429210040895537152)]} 0 2
[junit4:junit4] 2> 14280 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[32 (1429210040899731456)]} 0 0
[junit4:junit4] 2> 14280 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10032 (1429210040899731457)]} 0 0
[junit4:junit4] 2> 14282 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14283 T2931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49292__ymk_collection1",
[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:49292__ymk",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49292/_ymk"}
[junit4:junit4] 2> 14285 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1429210040901828608)]} 0 1
[junit4:junit4] 2> 14285 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10032 (1429210040901828609)]} 0 1
[junit4:junit4] 2> 14285 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[32 (1429210040901828608)]} 0 3
[junit4:junit4] 2> 14286 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10032 (1429210040901828609)]} 0 4
[junit4:junit4] 2> 14287 T2930 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> 14286 T2966 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> 14287 T2937 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> 14287 T2950 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> 14297 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[28 (-1429210040917557248)]} 0 0
[junit4:junit4] 2> 14299 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[28 (-1429210040919654400)]} 0 0
[junit4:junit4] 2> 14299 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10028 (-1429210040919654400)]} 0 0
[junit4:junit4] 2> 14301 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10028 (-1429210040921751552)]} 0 0
[junit4:junit4] 2> 14301 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[33 (1429210040921751552)]} 0 0
[junit4:junit4] 2> 14303 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10033 (1429210040923848704)]} 0 1
[junit4:junit4] 2> 14303 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[33 (1429210040923848704)]} 0 0
[junit4:junit4] 2> 14305 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10033 (1429210040925945856)]} 0 0
[junit4:junit4] 2> 14336 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[29 (-1429210040958451712)]} 0 0
[junit4:junit4] 2> 14337 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10029 (-1429210040959500288)]} 0 0
[junit4:junit4] 2> 14338 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[29 (-1429210040960548864)]} 0 0
[junit4:junit4] 2> 14339 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[10029 (-1429210040961597440)]} 0 0
[junit4:junit4] 2> 14340 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[34 (1429210040962646016)]} 0 1
[junit4:junit4] 2> 14341 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10034 (1429210040963694592)]} 0 0
[junit4:junit4] 2> 14342 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[34 (1429210040964743168)]} 0 0
[junit4:junit4] 2> 14344 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10034 (1429210040965791744)]} 0 1
[junit4:junit4] 2> 14397 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[30 (-1429210041022414848)]} 0 0
[junit4:junit4] 2> 14398 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[10030 (-1429210041023463424)]} 0 0
[junit4:junit4] 2> 14399 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[30 (-1429210041024512000)]} 0 0
[junit4:junit4] 2> 14400 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[10030 (-1429210041025560576)]} 0 0
[junit4:junit4] 2> 14402 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[35 (1429210041026609152)]} 0 1
[junit4:junit4] 2> 14403 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10035 (1429210041027657728)]} 0 1
[junit4:junit4] 2> 14404 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[35 (1429210041029754880)]} 0 0
[junit4:junit4] 2> 14405 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10035 (1429210041029754881)]} 0 1
[junit4:junit4] 2> 14424 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[33 (-1429210041050726400)]} 0 0
[junit4:junit4] 2> 14425 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[10033 (-1429210041051774976)]} 0 0
[junit4:junit4] 2> 14426 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[33 (-1429210041052823552)]} 0 0
[junit4:junit4] 2> 14426 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[10033 (-1429210041052823553)]} 0 0
[junit4:junit4] 2> 14428 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[36 (1429210041054920704)]} 0 0
[junit4:junit4] 2> 14429 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10036 (1429210041054920705)]} 0 1
[junit4:junit4] 2> 14431 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[36 (1429210041057017856)]} 0 1
[junit4:junit4] 2> 14431 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10036 (1429210041057017857)]} 0 1
[junit4:junit4] 2> 14490 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[35 (-1429210041119932416)]} 0 0
[junit4:junit4] 2> 14490 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[10035 (-1429210041119932417)]} 0 0
[junit4:junit4] 2> 14492 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[35 (-1429210041120980992)]} 0 1
[junit4:junit4] 2> 14492 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[10035 (-1429210041122029568)]} 0 0
[junit4:junit4] 2> 14494 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10037 (1429210041124126720)]} 0 0
[junit4:junit4] 2> 14494 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[37 (1429210041123078144)]} 0 1
[junit4:junit4] 2> 14496 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10037 (1429210041126223872)]} 0 0
[junit4:junit4] 2> 14496 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[37 (1429210041126223873)]} 0 0
[junit4:junit4] 2> 14539 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[10036 (-1429210041171312640)]} 0 0
[junit4:junit4] 2> 14539 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[36 (-1429210041171312641)]} 0 0
[junit4:junit4] 2> 14541 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[10036 (-1429210041173409792)]} 0 0
[junit4:junit4] 2> 14541 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[36 (-1429210041173409793)]} 0 0
[junit4:junit4] 2> 14543 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10038 (1429210041175506944)]} 0 0
[junit4:junit4] 2> 14543 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[38 (1429210041175506945)]} 0 0
[junit4:junit4] 2> 14545 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10038 (1429210041177604096)]} 0 0
[junit4:junit4] 2> 14551 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[38 (1429210041177604097)]} 0 6
[junit4:junit4] 2> 14620 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[10037 (-1429210041256247296)]} 0 0
[junit4:junit4] 2> 14621 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[37 (-1429210041257295872)]} 0 1
[junit4:junit4] 2> 14622 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[10037 (-1429210041258344448)]} 0 0
[junit4:junit4] 2> 14623 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[37 (-1429210041259393024)]} 0 1
[junit4:junit4] 2> 14625 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10039 (1429210041260441600)]} 0 1
[junit4:junit4] 2> 14625 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[39 (1429210041260441601)]} 0 1
[junit4:junit4] 2> 14627 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[39 (1429210041263587328)]} 0 1
[junit4:junit4] 2> 14627 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10039 (1429210041262538752)]} 0 1
[junit4:junit4] 2> 14694 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[40 (1429210041333841921)]} 0 0
[junit4:junit4] 2> 14695 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10040 (1429210041333841920)]} 0 1
[junit4:junit4] 2> 14697 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[40 (1429210041335939072)]} 0 1
[junit4:junit4] 2> 14697 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10040 (1429210041336987648)]} 0 1
[junit4:junit4] 2> 14775 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[41 (1429210041418776576)]} 0 0
[junit4:junit4] 2> 14775 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10041 (1429210041418776577)]} 0 0
[junit4:junit4] 2> 14778 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[41 (1429210041420873728)]} 0 1
[junit4:junit4] 2> 14778 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10041 (1429210041420873729)]} 0 1
[junit4:junit4] 2> 14841 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[38 (-1429210041487982592)]} 0 0
[junit4:junit4] 2> 14841 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[10038 (-1429210041487982593)]} 0 0
[junit4:junit4] 2> 14843 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[38 (-1429210041490079744)]} 0 0
[junit4:junit4] 2> 14843 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[10038 (-1429210041490079745)]} 0 0
[junit4:junit4] 2> 14845 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[42 (1429210041492176896)]} 0 0
[junit4:junit4] 2> 14845 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10042 (1429210041492176897)]} 0 0
[junit4:junit4] 2> 14847 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[42 (1429210041494274048)]} 0 0
[junit4:junit4] 2> 14848 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10042 (1429210041494274049)]} 0 1
[junit4:junit4] 2> 14911 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[39 (-1429210041561382912)]} 0 1
[junit4:junit4] 2> 14911 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[10039 (-1429210041561382913)]} 0 1
[junit4:junit4] 2> 14912 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[39 (-1429210041562431488)]} 0 0
[junit4:junit4] 2> 14913 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[10039 (-1429210041563480064)]} 0 0
[junit4:junit4] 2> 14915 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[43 (1429210041564528640)]} 0 1
[junit4:junit4] 2> 14915 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10043 (1429210041565577216)]} 0 0
[junit4:junit4] 2> 14917 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[43 (1429210041567674368)]} 0 0
[junit4:junit4] 2> 14918 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10043 (1429210041567674369)]} 0 1
[junit4:junit4] 2> 14997 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[44 (1429210041650511872)]} 0 1
[junit4:junit4] 2> 14997 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10044 (1429210041651560448)]} 0 0
[junit4:junit4] 2> 14999 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[44 (1429210041653657600)]} 0 0
[junit4:junit4] 2> 14999 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10044 (1429210041653657601)]} 0 0
[junit4:junit4] 2> 15073 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[45 (1429210041730203648)]} 0 1
[junit4:junit4] 2> 15073 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10045 (1429210041731252224)]} 0 1
[junit4:junit4] 2> 15075 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[45 (1429210041733349376)]} 0 0
[junit4:junit4] 2> 15075 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10045 (1429210041733349377)]} 0 0
[junit4:junit4] 2> 15110 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[46 (1429210041770049536)]} 0 0
[junit4:junit4] 2> 15110 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10046 (1429210041770049537)]} 0 0
[junit4:junit4] 2> 15113 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[46 (1429210041772146688)]} 0 1
[junit4:junit4] 2> 15113 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10046 (1429210041772146689)]} 0 1
[junit4:junit4] 2> 15120 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[46 (-1429210041780535296)]} 0 0
[junit4:junit4] 2> C361_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:49292__ymk, base_url=http://127.0.0.1:49292/_ymk}
[junit4:junit4] 2> 15120 T2969 C361 P49292 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:44043/_ymk/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 15120 T2969 C361 P49292 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:49292/_ymk START replicas=[http://127.0.0.1:44043/_ymk/collection1/] nUpdates=100
[junit4:junit4] 2> 15120 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10046 (-1429210041780535297)]} 0 0
[junit4:junit4] 2> 15121 T2969 C361 P49292 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 15121 T2969 C361 P49292 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 15121 T2969 C361 P49292 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 15121 T2969 C361 P49292 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 15121 T2945 C363 P44043 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 15121 T2969 C361 P49292 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4] 2> 15121 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[46 (-1429210041781583872)]} 0 0
[junit4:junit4] 2> 15122 T2969 C361 P49292 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:44043/_ymk/collection1/. core=collection1
[junit4:junit4] 2> 15122 T2943 C363 P44043 /update {wt=javabin&version=2} {delete=[10046 (-1429210041782632448)]} 0 0
[junit4:junit4] 2> 15123 T2969 C361 P49292 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15124 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[47 (1429210041784729600)]} 0 0
[junit4:junit4] 2> 15125 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10047 (1429210041784729601)]} 0 1
[junit4:junit4] 2> 15126 T2945 C363 P44043 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 15127 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[47 (1429210041786826752)]} 0 1
[junit4:junit4] 2> 15146 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10047 (1429210041787875328)]} 0 19
[junit4:junit4] 2> 15152 T2945 C363 P44043 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1b3141da lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b3147ca),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1b3141da lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b3147ca),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _0_Lucene41_0.pos, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_Pulsing41_0.tim, _1_Asserting_0.tip, _0_Pulsing41_0.tip, _0.nvd, _0_SimpleText_0.pst, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_Asserting_0.doc, _1.nvm, _1_Asserting_0.pos, _0.fnm, _1_Lucene41_0.tim, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _1_Lucene41_0.tip, _1_1.del, _0.nvm, _1_Pulsing41_0.pos, _1_Lucene41_0.pos, _1.fdx, _0_Pulsing41_0.pos, _0_Pulsing41_0.doc, _1_Pulsing41_0.tip, _1.fdt, _0_Lucene41_0.doc, _1_Pulsing41_0.tim, _1.si, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt, _1_SimpleText_0.pst]
[junit4:junit4] 2> 15153 T2945 C363 P44043 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _0_Lucene41_0.pos, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_Pulsing41_0.tim, _1_Asserting_0.tip, _0_Pulsing41_0.tip, _0.nvd, _0_SimpleText_0.pst, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_Asserting_0.doc, _1.nvm, _1_Asserting_0.pos, _0.fnm, _1_Lucene41_0.tim, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _1_Lucene41_0.tip, _1_1.del, _0.nvm, _1_Pulsing41_0.pos, _1_Lucene41_0.pos, _1.fdx, _0_Pulsing41_0.pos, _0_Pulsing41_0.doc, _1_Pulsing41_0.tip, _1.fdt, _0_Lucene41_0.doc, _1_Pulsing41_0.tim, _1.si, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt, _1_SimpleText_0.pst]
[junit4:junit4] 2> 15168 T2945 C363 P44043 oass.SolrIndexSearcher.<init> Opening Searcher@1b183735 realtime
[junit4:junit4] 2> 15169 T2945 C363 P44043 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 15169 T2945 C363 P44043 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 43
[junit4:junit4] 2> 15169 T2969 C361 P49292 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 15170 T2969 C361 P49292 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 15171 T2946 C363 P44043 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 15172 T2946 C363 P44043 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 15172 T2969 C361 P49292 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 15172 T2969 C361 P49292 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 15172 T2969 C361 P49292 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 15174 T2944 C363 P44043 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 15175 T2969 C361 P49292 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 41
[junit4:junit4] 2> 15175 T2969 C361 P49292 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/index.20130311142149651 forceNew: false
[junit4:junit4] 2> 15175 T2969 C361 P49292 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aefa9fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aefaf46) fullCopy=true
[junit4:junit4] 2> 15177 T2945 C363 P44043 REQ /replication {file=_0_Asserting_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15179 T2943 C363 P44043 REQ /replication {file=_1_Lucene41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15182 T2946 C363 P44043 REQ /replication {file=_0_Asserting_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15184 T2944 C363 P44043 REQ /replication {file=_0_Lucene41_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15186 T2945 C363 P44043 REQ /replication {file=_1_Asserting_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15188 T2943 C363 P44043 REQ /replication {file=_1.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15190 T2946 C363 P44043 REQ /replication {file=_1_Asserting_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15204 T2944 C363 P44043 REQ /replication {file=_0_Pulsing41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15207 T2945 C363 P44043 REQ /replication {file=_0_Pulsing41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15209 T2943 C363 P44043 REQ /replication {file=_1_Asserting_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15211 T2946 C363 P44043 REQ /replication {file=_0_SimpleText_0.pst&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15213 T2944 C363 P44043 REQ /replication {file=_0.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15215 T2945 C363 P44043 REQ /replication {file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15217 T2943 C363 P44043 REQ /replication {file=_0_Lucene41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15219 T2946 C363 P44043 REQ /replication {file=_0_Asserting_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15221 T2944 C363 P44043 REQ /replication {file=_0_Lucene41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15224 T2945 C363 P44043 REQ /replication {file=_1_Asserting_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15226 T2943 C363 P44043 REQ /replication {file=_1.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15228 T2946 C363 P44043 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15229 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[48 (1429210041893781504)]} 0 1
[junit4:junit4] 2> 15230 T2944 C363 P44043 REQ /replication {file=_1_Lucene41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15231 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[48 (1429210041896927232)]} 0 1
[junit4:junit4] 2> 15232 T2943 C363 P44043 REQ /replication {file=_1.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15234 T2946 C363 P44043 REQ /replication {file=_0_1.del&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15236 T2944 C363 P44043 REQ /replication {file=_1_Lucene41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15238 T2945 C363 P44043 REQ /replication {file=_1_Pulsing41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15240 T2943 C363 P44043 REQ /replication {file=_0.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15242 T2946 C363 P44043 REQ /replication {file=_1_1.del&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15244 T2944 C363 P44043 REQ /replication {file=_1_Pulsing41_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15247 T2943 C363 P44043 REQ /replication {file=_1.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15248 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10048 (1429210041913704448)]} 0 1
[junit4:junit4] 2> 15249 T2946 C363 P44043 REQ /replication {file=_1_Lucene41_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15250 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10048 (1429210041916850176)]} 0 0
[junit4:junit4] 2> 15251 T2944 C363 P44043 REQ /replication {file=_0_Pulsing41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15253 T2943 C363 P44043 REQ /replication {file=_0_Pulsing41_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15255 T2946 C363 P44043 REQ /replication {file=_1_Pulsing41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15257 T2945 C363 P44043 REQ /replication {file=_0_Lucene41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15259 T2944 C363 P44043 REQ /replication {file=_1.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15261 T2943 C363 P44043 REQ /replication {file=_1_Pulsing41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15263 T2946 C363 P44043 REQ /replication {file=_1.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15265 T2945 C363 P44043 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15268 T2944 C363 P44043 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15270 T2943 C363 P44043 REQ /replication {file=_0_Asserting_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15272 T2946 C363 P44043 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15274 T2945 C363 P44043 REQ /replication {file=_1_SimpleText_0.pst&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 15275 T2969 C361 P49292 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 15275 T2969 C361 P49292 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130311142149651
[junit4:junit4] 2> 15276 T2969 C361 P49292 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 15276 T2969 C361 P49292 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 15276 T2969 C361 P49292 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 15277 T2969 C361 P49292 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/index/ new=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/index.20130311142149651
[junit4:junit4] 2> 15280 T2969 C361 P49292 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aefa9fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aefaf46),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _0_Lucene41_0.pos, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_Pulsing41_0.tim, _1_Asserting_0.tip, _0_Pulsing41_0.tip, _0.nvd, _0_SimpleText_0.pst, _0.si, _0_Lucene41_0.tim, _0_Asserting_0.doc, _0_Lucene41_0.tip, _1.nvm, _1_Asserting_0.pos, _0.fnm, _1_Lucene41_0.tim, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _1_Lucene41_0.tip, _1_1.del, _0.nvm, _1_Pulsing41_0.pos, _1_Lucene41_0.pos, _1.fdx, _0_Pulsing41_0.pos, _0_Pulsing41_0.doc, _1_Pulsing41_0.tip, _1.fdt, _0_Lucene41_0.doc, _1_Pulsing41_0.tim, _1.si, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt, _1_SimpleText_0.pst]
[junit4:junit4] 2> 15281 T2969 C361 P49292 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _0_Lucene41_0.pos, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_Pulsing41_0.tim, _1_Asserting_0.tip, _0_Pulsing41_0.tip, _0.nvd, _0_SimpleText_0.pst, _0.si, _0_Lucene41_0.tim, _0_Asserting_0.doc, _0_Lucene41_0.tip, _1.nvm, _1_Asserting_0.pos, _0.fnm, _1_Lucene41_0.tim, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _1_Lucene41_0.tip, _1_1.del, _0.nvm, _1_Pulsing41_0.pos, _1_Lucene41_0.pos, _1.fdx, _0_Pulsing41_0.pos, _0_Pulsing41_0.doc, _1_Pulsing41_0.tip, _1.fdt, _0_Lucene41_0.doc, _1_Pulsing41_0.tim, _1.si, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt, _1_SimpleText_0.pst]
[junit4:junit4] 2> 15283 T2969 C361 P49292 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 15285 T2969 C361 P49292 oass.SolrIndexSearcher.<init> Opening Searcher@1af04c12 main
[junit4:junit4] 2> 15286 T2968 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1af04c12 main{StandardDirectoryReader(segments_2:6:nrt _0(4.3):C69/38 _1(4.3):C24/12)}
[junit4:junit4] 2> 15286 T2969 C361 P49292 oash.SnapPuller$2.preClose removing old index files BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1aecab67 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aecb157)
[junit4:junit4] 2> 15286 T2969 C361 P49292 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/index
[junit4:junit4] 2> 15287 T2969 C361 P49292 oash.SnapPuller$2.postClose removing old index directory BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1aecab67 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aecb157)
[junit4:junit4] 2> 15288 T2969 C361 P49292 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4] 2> 15291 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[48 (-1429210041959841792)]} 0 0
[junit4:junit4] 2> 15293 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[48 (-1429210041961938944)]} 0 0
[junit4:junit4] 2> 15294 T2977 C361 P49292 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.RecoveryZkTest-1363000894497/jetty2/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=6361
[junit4:junit4] 2> 15295 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[49 (1429210041964036096)]} 0 0
[junit4:junit4] 2> 15296 T2977 C361 P49292 oasu.DirectUpdateHandler2.commit start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 15298 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[49 (1429210041966133248)]} 0 1
[junit4:junit4] 2> 15301 T2977 C361 P49292 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aefa9fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aefaf46),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _0_Lucene41_0.pos, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_Pulsing41_0.tim, _1_Asserting_0.tip, _0_Pulsing41_0.tip, _0.nvd, _0_SimpleText_0.pst, _0.si, _0_Lucene41_0.tim, _0_Asserting_0.doc, _0_Lucene41_0.tip, _1.nvm, _1_Asserting_0.pos, _0.fnm, _1_Lucene41_0.tim, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _1_Lucene41_0.tip, _1_1.del, _0.nvm, _1_Pulsing41_0.pos, _1_Lucene41_0.pos, _1.fdx, _0_Pulsing41_0.pos, _0_Pulsing41_0.doc, _1_Pulsing41_0.tip, _1.fdt, _0_Lucene41_0.doc, _1_Pulsing41_0.tim, _1.si, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt, _1_SimpleText_0.pst]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aefa9fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aefaf46),segFN=segments_3,generation=3,filenames=[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _0_Lucene41_0.pos, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_Pulsing41_0.tim, _1_Asserting_0.tip, _0_Pulsing41_0.tip, _0.nvd, _0_SimpleText_0.pst, _0.si, _0_Lucene41_0.tim, _0_Asserting_0.doc, _0_Lucene41_0.tip, _1.nvm, _1_Asserting_0.pos, _0.fnm, _1_Lucene41_0.tim, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _1_Lucene41_0.tip, _1_1.del, _0.nvm, _1_Pulsing41_0.pos, _1_Lucene41_0.pos, _1.fdx, _0_Pulsing41_0.pos, _0_Pulsing41_0.doc, _1_Pulsing41_0.tip, _1.fdt, _0_Lucene41_0.doc, _1_Pulsing41_0.tim, _1.si, _0.fdx, _0_Asserting_0.pos, segments_3, _0.fdt, _1_SimpleText_0.pst]
[junit4:junit4] 2> 15301 T2977 C361 P49292 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _0_Lucene41_0.pos, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_Pulsing41_0.tim, _1_Asserting_0.tip, _0_Pulsing41_0.tip, _0.nvd, _0_SimpleText_0.pst, _0.si, _0_Lucene41_0.tim, _0_Asserting_0.doc, _0_Lucene41_0.tip, _1.nvm, _1_Asserting_0.pos, _0.fnm, _1_Lucene41_0.tim, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _1_Lucene41_0.tip, _1_1.del, _0.nvm, _1_Pulsing41_0.pos, _1_Lucene41_0.pos, _1.fdx, _0_Pulsing41_0.pos, _0_Pulsing41_0.doc, _1_Pulsing41_0.tip, _1.fdt, _0_Lucene41_0.doc, _1_Pulsing41_0.tim, _1.si, _0.fdx, _0_Asserting_0.pos, segments_3, _0.fdt, _1_SimpleText_0.pst]
[junit4:junit4] 2> 15304 T2977 C361 P49292 oass.SolrIndexSearcher.<init> Opening Searcher@1b0f6316 main
[junit4:junit4] 2> 15304 T2977 C361 P49292 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 15305 T2968 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b0f6316 main{StandardDirectoryReader(segments_2:6:nrt _0(4.3):C69/38 _1(4.3):C24/12)}
[junit4:junit4] 2> 15306 T2977 C361 P49292 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=6361}
[junit4:junit4] 2> 15306 T2969 C361 P49292 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 15306 T2969 C361 P49292 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 15306 T2969 C361 P49292 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15307 T2969 C361 P49292 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 15310 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[10048 (-1429210041979764736)]} 0 0
[junit4:junit4] 2> 15312 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[10048 (-1429210041981861888)]} 0 0
[junit4:junit4] 2> 15314 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10049 (1429210041983959040)]} 0 0
[junit4:junit4] 2> 15317 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10049 (1429210041986056192)]} 0 1
[junit4:junit4] 2> 15321 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[50 (1429210041991299072)]} 0 0
[junit4:junit4] 2> 15324 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[50 (1429210041993396224)]} 0 1
[junit4:junit4] 2> 15340 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10050 (1429210042011222016)]} 0 0
[junit4:junit4] 2> 15342 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10050 (1429210042013319168)]} 0 0
[junit4:junit4] 2> 15425 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[51 (1429210042099302400)]} 0 1
[junit4:junit4] 2> 15428 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[51 (1429210042102448128)]} 0 1
[junit4:junit4] 2> 15443 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10051 (1429210042118176768)]} 0 1
[junit4:junit4] 2> 15445 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10051 (1429210042121322496)]} 0 0
[junit4:junit4] 2> 15504 T2924 C362 P60104 /update {wt=javabin&version=2} {delete=[50 (-1429210042183188480)]} 0 0
[junit4:junit4] 2> 15506 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[50 (-1429210042185285632)]} 0 0
[junit4:junit4] 2> 15508 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[52 (1429210042187382784)]} 0 0
[junit4:junit4] 2> 15511 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[52 (1429210042189479936)]} 0 1
[junit4:junit4] 2> 15521 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[10050 (-1429210042201014272)]} 0 0
[junit4:junit4] 2> 15523 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[10050 (-1429210042203111424)]} 0 0
[junit4:junit4] 2> 15526 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10052 (1429210042205208576)]} 0 1
[junit4:junit4] 2> 15528 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10052 (1429210042208354304)]} 0 0
[junit4:junit4] 2> 15556 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[52 (-1429210042237714432)]} 0 0
[junit4:junit4] 2> 15558 T2944 C363 P44043 /update {wt=javabin&version=2} {delete=[52 (-1429210042239811584)]} 0 0
[junit4:junit4] 2> 15560 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[53 (1429210042241908736)]} 0 0
[junit4:junit4] 2> 15562 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[53 (1429210042244005888)]} 0 0
[junit4:junit4] 2> 15573 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10052 (-1429210042255540224)]} 0 0
[junit4:junit4] 2> 15575 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[10052 (-1429210042257637376)]} 0 0
[junit4:junit4] 2> 15577 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10053 (1429210042259734528)]} 0 0
[junit4:junit4] 2> 15580 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10053 (1429210042261831680)]} 0 1
[junit4:junit4] 2> 15622 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[54 (1429210042305871872)]} 0 1
[junit4:junit4] 2> 15624 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[54 (1429210042309017600)]} 0 0
[junit4:junit4] 2> 15640 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10054 (1429210042324746240)]} 0 1
[junit4:junit4] 2> 15642 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10054 (1429210042327891968)]} 0 0
[junit4:junit4] 2> 15684 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[55 (1429210042370883584)]} 0 1
[junit4:junit4] 2> 15686 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[55 (1429210042374029312)]} 0 0
[junit4:junit4] 2> 15699 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[56 (1429210042386612224)]} 0 1
[junit4:junit4] 2> 15701 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[56 (1429210042389757952)]} 0 1
[junit4:junit4] 2> 15701 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10055 (1429210042389757952)]} 0 0
[junit4:junit4] 2> 15704 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[10055 (1429210042391855104)]} 0 1
[junit4:junit4] 2> 15716 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[10056 (1429210042405486592)]} 0 0
[junit4:junit4] 2> 15719 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[10056 (1429210042407583744)]} 0 1
[junit4:junit4] 2> 15776 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[57 (1429210042467352576)]} 0 1
[junit4:junit4] 2> 15778 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[57 (1429210042470498304)]} 0 0
[junit4:junit4] 2> 15791 T2931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15791 T2931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[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:49292__ymk",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49292/_ymk"}
[junit4:junit4] 2> 15794 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10057 (1429210042486226944)]} 0 1
[junit4:junit4] 2> 15794 T2937 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> 15794 T2930 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> 15794 T2950 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> 15794 T2966 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> C361_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:49292__ymk, base_url=http://127.0.0.1:49292/_ymk}
[junit4:junit4] 2> 15800 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10057 (1429210042490421248)]} 0 1
[junit4:junit4] 2> 15801 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10057 (1429210042490421248)]} 0 4
[junit4:junit4] 2> 15834 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[55 (-1429210042529218560)]} 0 0
[junit4:junit4] 2> 15838 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[55 (-1429210042532364288)]} 0 0
[junit4:junit4] 2> 15839 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[55 (-1429210042532364288)]} 0 3
[junit4:junit4] 2> 15841 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[58 (1429210042536558592)]} 0 0
[junit4:junit4] 2> 15846 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[58 (1429210042538655744)]} 0 1
[junit4:junit4] 2> 15846 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[58 (1429210042538655744)]} 0 3
[junit4:junit4] 2> 15857 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10055 (-1429210042553335808)]} 0 0
[junit4:junit4] 2> 15861 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10055 (-1429210042555432960)]} 0 1
[junit4:junit4] 2> 15861 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[10055 (-1429210042555432960)]} 0 2
[junit4:junit4] 2> 15863 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10058 (1429210042559627264)]} 0 0
[junit4:junit4] 2> 15867 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10058 (1429210042561724416)]} 0 0
[junit4:junit4] 2> 15868 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10058 (1429210042561724416)]} 0 3
[junit4:junit4] 2> 15896 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[58 (-1429210042594230272)]} 0 1
[junit4:junit4] 2> 15899 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[58 (-1429210042596327424)]} 0 0
[junit4:junit4] 2> 15900 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[58 (-1429210042596327424)]} 0 2
[junit4:junit4] 2> 15902 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[59 (1429210042600521728)]} 0 0
[junit4:junit4] 2> 15907 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[59 (1429210042602618880)]} 0 0
[junit4:junit4] 2> 15907 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[59 (1429210042602618880)]} 0 3
[junit4:junit4] 2> 15917 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10058 (-1429210042616250368)]} 0 0
[junit4:junit4] 2> 15921 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10058 (-1429210042618347520)]} 0 0
[junit4:junit4] 2> 15921 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[10058 (-1429210042618347520)]} 0 2
[junit4:junit4] 2> 15924 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10059 (1429210042622541824)]} 0 1
[junit4:junit4] 2> 15928 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10059 (1429210042625687552)]} 0 1
[junit4:junit4] 2> 15928 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10059 (1429210042625687552)]} 0 2
[junit4:junit4] 2> 16009 T2923 C362 P60104 /update {wt=javabin&version=2} {delete=[59 (-1429210042712719360)]} 0 0
[junit4:junit4] 2> 16012 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[59 (-1429210042714816512)]} 0 0
[junit4:junit4] 2> 16013 T2946 C363 P44043 /update {wt=javabin&version=2} {delete=[59 (-1429210042714816512)]} 0 2
[junit4:junit4] 2> 16015 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[60 (1429210042719010816)]} 0 0
[junit4:junit4] 2> 16020 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[60 (1429210042721107968)]} 0 0
[junit4:junit4] 2> 16021 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[60 (1429210042721107968)]} 0 4
[junit4:junit4] 2> 16029 T2926 C362 P60104 /update {wt=javabin&version=2} {delete=[10059 (-1429210042733690880)]} 0 0
[junit4:junit4] 2> 16033 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10059 (-1429210042735788032)]} 0 0
[junit4:junit4] 2> 16033 T2945 C363 P44043 /update {wt=javabin&version=2} {delete=[10059 (-1429210042735788032)]} 0 2
[junit4:junit4] 2> 16036 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10060 (1429210042739982336)]} 0 1
[junit4:junit4] 2> 16040 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10060 (1429210042743128064)]} 0 0
[junit4:junit4] 2> 16040 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10060 (1429210042743128064)]} 0 2
[junit4:junit4] 2> 16071 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[61 (1429210042777731072)]} 0 0
[junit4:junit4] 2> 16076 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[61 (1429210042780876800)]} 0 1
[junit4:junit4] 2> 16076 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[61 (1429210042780876800)]} 0 3
[junit4:junit4] 2> 16089 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[62 (1429210042796605440)]} 0 1
[junit4:junit4] 2> 16091 T2925 C362 P60104 /update {wt=javabin&version=2} {add=[10061 (1429210042797654016)]} 0 1
[junit4:junit4] 2> 16094 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[62 (1429210042798702592)]} 0 1
[junit4:junit4] 2> 16094 T2944 C363 P44043 /update {wt=javabin&version=2} {add=[62 (1429210042798702592)]} 0 3
[junit4:junit4] 2> 16095 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10061 (1429210042800799744)]} 0 0
[junit4:junit4] 2> 16095 T2943 C363 P44043 /update {wt=javabin&version=2} {add=[10061 (1429210042800799744)]} 0 2
[junit4:junit4] 2> 16108 T2926 C362 P60104 /update {wt=javabin&version=2} {add=[10062 (1429210042815479808)]} 0 1
[junit4:junit4] 2> 16111 T2924 C362 P60104 /update {wt=javabin&version=2} {add=[63 (1429210042818625536)]} 0 1
[junit4:junit4] 2> 16112 T2959 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10062 (1429210042818625536)]} 0 0
[junit4:junit4] 2> 16113 T2945 C363 P44043 /update {wt=javabin&version=2} {add=[10062 (1429210042818625536)]} 0 3
[junit4:junit4] 2> 16116 T2962 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[63 (1429210042821771264)]} 0 1
[junit4:junit4] 2> 16116 T2946 C363 P44043 /update {wt=javabin&version=2} {add=[63 (1429210042821771264)]} 0 3
[junit4:junit4] 2> 16121 T2908 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 16121 T2908 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16125 T2908 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1aec30f1
[junit4:junit4] 2> 16129 T2923 C362 P60104 /update {wt=javabin&version=2} {add=[10063 (1429210042838548480)]} 0 0
[junit4:junit4] 2> 16134 T2961 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10063 (1429210042840645632)]} 0 1
[junit4:junit4] 2> 16134 T2961 C361 P49292 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1aec30f1
[junit4:junit4] 2> 16135 T2961 C361 P49292 oasc.SolrException.log SEVERE org.apache.solr.common.SolrException: Failed to unregister info bean: debug
[junit4:junit4] 2> at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:178)
[junit4:junit4] 2> at org.apache.solr.core.JmxMonitoredMap.clear(JmxMonitoredMap.java:116)
[junit4:junit4] 2> at org.apache.solr.core.SolrCore.close(SolrCore.java:970)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:372)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:142)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:275)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1074)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
[junit4:junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:365)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:999)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:948)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
[junit4:junit4] 2> at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:609)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2> Caused by: javax.management.InstanceNotFoundException: solr/collection1:type=debug,id=debug
[junit4:junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getMBean(DefaultMBeanServerInterceptor.java:1094)
[junit4:junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:415)
[junit4:junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:403)
[junit4:junit4] 2> at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:507)
[junit4:junit4] 2> at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:175)
[junit4:junit4] 2> ... 29 more
[junit4:junit4] 2>
[junit4:junit4] 2> 16136 T2961 C361 P49292 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=13,adds=13,deletesById=6,deletesByQuery=0,errors=0,cumulative_adds=57,cumulative_deletesById=26,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 16136 T2961 C361 P49292 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 16137 T2908 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=13,deletesById=6,deletesByQuery=0,errors=0,cumulative_adds=57,cumulative_deletesById=26,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 16137 T2961 C361 P49292 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 16138 T2961 C361 P49292 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 16160 T2961 C361 P49292 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aefa9fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aefaf46),segFN=segments_3,generation=3,filenames=[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _0_Lucene41_0.pos, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_Pulsing41_0.tim, _1_Asserting_0.tip, _0_Pulsing41_0.tip, _0.nvd, _0_SimpleText_0.pst, _0.si, _0_Lucene41_0.tim, _0_Asserting_0.doc, _0_Lucene41_0.tip, _1.nvm, _1_Asserting_0.pos, _0.fnm, _1_Lucene41_0.tim, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _1_Lucene41_0.tip, _1_1.del, _0.nvm, _1_Pulsing41_0.pos, _1_Lucene41_0.pos, _1.fdx, _0_Pulsing41_0.pos, _0_Pulsing41_0.doc, _1_Pulsing41_0.tip, _1.fdt, _0_Lucene41_0.doc, _1_Pulsing41_0.tim, _1.si, _0.fdx, _0_Asserting_0.pos, segments_3, _0.fdt, _1_SimpleText_0.pst]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aefa9fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aefaf46),segFN=segments_4,generation=4,filenames=[_1_Lucene41_0.doc, _0_Lucene41_0.pos, _3.fdt, _1.fnm, _1_Asserting_0.tim, _3.nvd, _3_Lucene41_0.pos, _0_Pulsing41_0.tim, _3_SimpleText_0.pst, _0_Pulsing41_0.tip, _1_Asserting_0.tip, _0_SimpleText_0.pst, _3.nvm, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_Asserting_0.doc, _1_Asserting_0.pos, _1.nvm, _0.fnm, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _3_Pulsing41_0.pos, _1.fdx, _1_Lucene41_0.pos, _1_Pulsing41_0.tip, _3_Lucene41_0.doc, _0_Lucene41_0.doc, _1.fdt, _1_Pulsing41_0.tim, _3.si, _3_Pulsing41_0.doc, _1_SimpleText_0.pst, _0_Asserting_0.tim, _0_Asserting_0.tip, _1_Asserting_0.doc, _3.fnm, _3_Asserting_0.pos, _3_1.del, _3_Lucene41_0.tip, _0.nvd, _3_Pulsing41_0.tim, _3_Lucene41_0.tim, _3_Pulsing41_0.tip, _0.si, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _0.nvm, _1_1.del, _1_Pulsing41_0.pos, _3.fdx, _0_Pulsing41_0.doc, _0_Pulsing41_0.pos, _3_Asserting_0.tim, _3_Asserting_0.tip, _3_Asserting_0.doc, _1.si, _0.fdx, _0_Asserting_0.pos, _0.fdt, segments_4]
[junit4:junit4] 2> 16161 T2961 C361 P49292 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_1_Lucene41_0.doc, _0_Lucene41_0.pos, _3.fdt, _1.fnm, _1_Asserting_0.tim, _3.nvd, _3_Lucene41_0.pos, _0_Pulsing41_0.tim, _3_SimpleText_0.pst, _0_Pulsing41_0.tip, _1_Asserting_0.tip, _0_SimpleText_0.pst, _3.nvm, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_Asserting_0.doc, _1_Asserting_0.pos, _1.nvm, _0.fnm, _1.nvd, _0_1.del, _1_Pulsing41_0.doc, _3_Pulsing41_0.pos, _1.fdx, _1_Lucene41_0.pos, _1_Pulsing41_0.tip, _3_Lucene41_0.doc, _0_Lucene41_0.doc, _1.fdt, _1_Pulsing41_0.tim, _3.si, _3_Pulsing41_0.doc, _1_SimpleText_0.pst, _0_Asserting_0.tim, _0_Asserting_0.tip, _1_Asserting_0.doc, _3.fnm, _3_Asserting_0.pos, _3_1.del, _3_Lucene41_0.tip, _0.nvd, _3_Pulsing41_0.tim, _3_Lucene41_0.tim, _3_Pulsing41_0.tip, _0.si, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _0.nvm, _1_1.del, _1_Pulsing41_0.pos, _3.fdx, _0_Pulsing41_0.doc, _0_Pulsing41_0.pos, _3_Asserting_0.tim, _3_Asserting_0.tip, _3_Asserting_0.doc, _1.si, _0.fdx, _0_Asserting_0.pos, _0.fdt, segments_4]
[junit4:junit4] 2> 16172 T2925 C362 P60104 /update {wt=javabin&version=2} {delete=[60 (-1429210042883637248)]} 0 0
[junit4:junit4] 2> 16176 T2960 C361 P49292 /update {distrib.from=http://127.0.0.1:44043/_ymk/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {} 0 0
[junit4:junit4] 2> 16177 T2960 C361 P49292 oasc.SolrException.log SEVERE java.lang.RuntimeException: SolrCoreState already closed
[junit4:junit4] 2> at org.apache.solr.update.DefaultSolrCoreState.getIndexWriter(DefaultSolrCoreState.java:84)
[junit4:junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.delete(DirectUpdateHandler2.java:288)
[junit4:junit4] 2> at org.apache.solr.update.processor.RunUpdateProcessor.processDelete(RunUpdateProcessorFactory.java:77)
[junit4:junit4] 2> at org.apache.solr.update.processor.UpdateRequestProcessor.processDelete(UpdateRequestProcessor.java:55)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalDelete(DistributedUpdateProcessor.java:456)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.versionDelete(DistributedUpdateProcessor.java:1031)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processDelete(DistributedUpdateProcessor.java:717)
[junit4:junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessor.processDelete(LogUpdateProcessorFactory.java:121)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.processDelete(XMLLoader.java:347)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.processUpdate(XMLLoader.java:277)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.load(XMLLoader.java:173)
[junit4:junit4] 2> at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:93)
[junit4:junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:74)
[junit4:junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
[junit4:junit4] 2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1811)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:638)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:344)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:142)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:275)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1074)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
[junit4:junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:365)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:999)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:948)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
[junit4:junit4] 2> at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:609)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2>
[junit4:junit4] 2> 16179 T2960 C361 P49292 oasc.SolrException.log SEVERE null:java.lang.RuntimeException: SolrCoreState already closed
[junit4:junit4] 2> at org.apache.solr.update.DefaultSolrCoreState.getIndexWriter(DefaultSolrCoreState.java:84)
[junit4:junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.delete(DirectUpdateHandler2.java:288)
[junit4:junit4] 2> at org.apache.solr.update.processor.RunUpdateProcessor.processDelete(RunUpdateProcessorFactory.java:77)
[junit4:junit4] 2> at org.apache.solr.update.processor.UpdateRequestProcessor.processDelete(UpdateRequestProcessor.java:55)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalDelete(DistributedUpdateProcessor.java:456)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.versionDelete(DistributedUpdateProcessor.java:1031)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processDelete(DistributedUpdateProcessor.java:717)
[junit4:junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessor.processDelete(LogUpdateProcessorFactory.java:121)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.processDelete(XMLLoader.java:347)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.processUpdate(XMLLoader.java:277)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.load(XMLLoader.java:173)
[junit4:junit4] 2> at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:93)
[junit4:junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:74)
[junit4:junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
[junit4:junit4] 2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1811)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:638)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:344)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:142)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[...truncated too long message...]
crazy): {}, locale=el_GR, timezone=Africa/Nairobi
[junit4:junit4] 2> NOTE: Linux 3.2.0-38-generic i386/Oracle Corporation 1.6.0_33 (32-bit)/cpus=8,threads=2,free=165052224,total=346308608
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestGroupingSearch, OverseerCollectionProcessorTest, SuggesterTest, TestStressVersions, TestPropInjectDefaults, TestCharFilters, TestWriterPerf, TestLMDirichletSimilarityFactory, MoreLikeThisHandlerTest, TestTrie, TestFieldTypeResource, SynonymTokenizerTest, PolyFieldTest, ReturnFieldsTest, TestDynamicFieldCollectionResource, FileBasedSpellCheckerTest, TestDocSet, DateFieldTest, JsonLoaderTest, UpdateRequestProcessorFactoryTest, TestFastLRUCache, TestPhraseSuggestions, TestJoin, SyncSliceTest, TestCollationKeyRangeQueries, AnalysisAfterCoreReloadTest, CacheHeaderTest, QueryElevationComponentTest, TestDocumentBuilder, TestSweetSpotSimilarityFactory, TestFieldResource, TestValueSourceCache, OverseerTest, CSVRequestHandlerTest, TestExtendedDismaxParser, ZkCLITest, PreAnalyzedFieldTest, TestSolrCoreProperties, SliceStateTest, TestXIncludeConfig, ResponseLogComponentTest, DistributedTermsComponentTest, ResourceLoaderTest, UUIDFieldTest, CircularListTest, SpellingQueryConverterTest, TestSearchPerf, TestConfig, IndexSchemaTest, TestSolrDeletionPolicy1, TestRealTimeGet, TestBadConfig, TestFunctionQuery, DirectUpdateHandlerOptimizeTest, TestPluginEnable, UnloadDistributedZkTest, SuggesterFSTTest, PeerSyncTest, TestPerFieldSimilarity, ExternalFileFieldSortTest, FieldMutatingUpdateProcessorTest, PrimUtilsTest, LukeRequestHandlerTest, PluginInfoTest, TermVectorComponentTest, TestReversedWildcardFilterFactory, BasicDistributedZkTest, BasicDistributedZk2Test, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, RecoveryZkTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RecoveryZkTest -Dtests.seed=E7B71485F93E038B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=el_GR -Dtests.timezone=Africa/Nairobi -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR 0.00s J0 | RecoveryZkTest (suite) <<<
[junit4:junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=2967, name=coreLoadExecutor-1918-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
[junit4:junit4] > at java.lang.Thread.getStackTrace(Thread.java:1479)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:520)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:986)
[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:34)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:272)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:224)
[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:744)
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:619)
[junit4:junit4] > at org.apache.solr.core.CoreContainer.createFromZk(CoreContainer.java:874)
[junit4:junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:957)
[junit4:junit4] > at org.apache.solr.core.CoreContainer$2.call(CoreContainer.java:580)
[junit4:junit4] > at org.apache.solr.core.CoreContainer$2.call(CoreContainer.java:575)
[junit4:junit4] > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
[junit4:junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:138)
[junit4:junit4] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
[junit4:junit4] > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
[junit4:junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:138)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] > Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aec7bbd lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aec828c)
[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:616)
[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] > Throwable #2: com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=2969, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
[junit4:junit4] > at java.lang.Thread.getStackTrace(Thread.java:1479)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:520)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:986)
[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:34)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:272)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:224)
[junit4:junit4] > at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:383)
[junit4:junit4] > at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:281)
[junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:153)
[junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:409)
[junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:223)
[junit4:junit4] > Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aefa9fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@1aefaf46)
[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:616)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] Completed on J0 in 37.93s, 1 test, 2 errors <<< FAILURES!
[...truncated 401 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:361: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1213: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:877: There were test failures: 271 suites, 1141 tests, 2 suite-level errors, 13 ignored (7 assumptions)
Total time: 77 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jrockit-jdk1.6.0_33-R28.2.4-4.1.0 -XnoOpt
Email was triggered for: Failure
Sending email for trigger: Failure