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/05 18:35:28 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b79) - Build #
4583 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4583/
Java: 32bit/jdk1.8.0-ea-b79 -server -XX:+UseG1GC
All tests passed
Build Log:
[...truncated 5905 lines...]
[junit4:junit4] ERROR: JVM J0 ended with an exception, command line: /var/lib/jenkins/tools/java/32bit/jdk1.8.0-ea-b79/jre/bin/java -server -XX:+UseG1GC -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/heapdumps -Dtests.prefix=tests -Dtests.seed=FE2388371D24A1F6 -Xmx512M -Dtests.iters= -Dtests.verbose=false -Dtests.infostream=false -Dtests.codec=random -Dtests.postingsformat=random -Dtests.docvaluesformat=random -Dtests.locale=random -Dtests.timezone=random -Dtests.directory=random -Dtests.linedocsfile=europarl.lines.txt.gz -Dtests.luceneMatchVersion=5.0 -Dtests.cleanthreads=perMethod -Djava.util.logging.config.file=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/tools/junit4/logging.properties -Dtests.nightly=false -Dtests.weekly=false -Dtests.slow=true -Dtests.asserts.gracious=false -Dtests.multiplier=3 -DtempDir=. -Djava.io.tmpdir=. -Djunit4.tempDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/uima/test/temp -Dclover.db.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/clover/db -Djava.security.manager=org.apache.lucene.util.TestSecurityManager -Djava.security.policy=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/tools/junit4/tests.policy -Dlucene.version=5.0-SNAPSHOT -Djetty.testMode=1 -Djetty.insecurerandom=1 -Dsolr.directoryFactory=org.apache.solr.core.MockDirectoryFactory -Djava.awt.headless=true -Dfile.encoding=ISO-8859-1 -classpath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/uima/classes/test:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/test-framework/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/codecs/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/common/lucene-analyzers-common-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/analysis/uima/src/test-files:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/analysis/uima/lib/Tagger-2.3.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/analysis/uima/lib/WhitespaceTokenizer-2.3.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/analysis/uima/lib/uimaj-core-2.3.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/core/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/test-framework/lib/junit-4.10.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/test-framework/lib/randomizedtesting-runner-2.0.8.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/uima/classes/java:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/var/lib/jenkins/.ant/lib/ivy-2.3.0.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/var/lib/jenkins/tools/java/32bit/jdk1.8.0-ea-b79/lib/tools.jar:/var/lib/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.8.jar -ea:org.apache.lucene... -ea:org.apache.solr... com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -flush -eventsfile /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/uima/test/temp/junit4-J0-20130305_170710_622.events @/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/uima/test/temp/junit4-J0-20130305_170710_622.suites
[junit4:junit4] ERROR: JVM J0 ended with an exception: Forked process returned with error code: 137.
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1253)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:66)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:821)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:818)
[junit4:junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4:junit4] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
[junit4:junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit4:junit4] at java.lang.Thread.run(Thread.java:722)
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:361: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build.xml:548: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1758: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/analysis/build.xml:105: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/analysis/build.xml:38: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/module-build.xml:61: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1213: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:877: At least one slave process threw an exception, first: Forked process returned with error code: 137.
Total time: 43 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.8.0-ea-b79 -server -XX:+UseG1GC
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux
(64bit/jrockit-jdk1.6.0_33-R28.2.4-4.1.0) - Build # 4584 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4584/
Java: 64bit/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=2155, name=coreLoadExecutor-1015-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=2155, name=coreLoadExecutor-1015-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:33)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:267)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:223)
at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:244)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:458)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:733)
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(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c5d7b1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c5d821b))
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=2157, 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=2157, 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:33)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:267)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:223)
at org.apache.solr.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(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c3ebff7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c3ec567))
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 8510 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4] 2> 56284 T561 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4] 2> 0 T2096 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /f_/f
[junit4:junit4] 2> 29 T2096 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-RecoveryZkTest-1362512052583
[junit4:junit4] 2> 30 T2096 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 31 T2097 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 31 T2097 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 31 T2097 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 32 T2097 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 32 T2097 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 32 T2097 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 131 T2096 oasc.ZkTestServer.run start zk server on port:34660
[junit4:junit4] 2> 131 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d4c03ce
[junit4:junit4] 2> 132 T2102 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 132 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 133 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38128
[junit4:junit4] 2> 133 T2102 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 133 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38128
[junit4:junit4] 2> 134 T2100 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 171 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0000 with negotiated timeout 10000 for client /127.0.0.1:38128
[junit4:junit4] 2> 171 T2102 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0000, negotiated timeout = 10000
[junit4:junit4] 2> 171 T2103 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d4c03ce name:ZooKeeperConnection Watcher:127.0.0.1:34660 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 172 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 172 T2096 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 175 T2101 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d3c0c016a0000
[junit4:junit4] 2> 175 T2103 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 175 T2098 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38128 which had sessionid 0x13d3c0c016a0000
[junit4:junit4] 2> 175 T2096 oaz.ZooKeeper.close Session: 0x13d3c0c016a0000 closed
[junit4:junit4] 2> 176 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d4c5f40
[junit4:junit4] 2> 177 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 177 T2104 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 178 T2104 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 178 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38129
[junit4:junit4] 2> 178 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38129
[junit4:junit4] 2> 179 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0001 with negotiated timeout 10000 for client /127.0.0.1:38129
[junit4:junit4] 2> 179 T2104 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0001, negotiated timeout = 10000
[junit4:junit4] 2> 180 T2105 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d4c5f40 name:ZooKeeperConnection Watcher:127.0.0.1:34660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 180 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 180 T2096 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 183 T2096 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 184 T2096 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 186 T2096 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 188 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 189 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 193 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 194 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 197 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 198 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 202 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 202 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 205 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 206 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 208 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 209 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 211 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 212 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 214 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 215 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 217 T2096 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 217 T2096 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 219 T2101 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d3c0c016a0001
[junit4:junit4] 2> 220 T2105 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 220 T2098 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38129 which had sessionid 0x13d3c0c016a0001
[junit4:junit4] 2> 220 T2096 oaz.ZooKeeper.close Session: 0x13d3c0c016a0001 closed
[junit4:junit4] 2> 327 T2096 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 329 T2096 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55620
[junit4:junit4] 2> 330 T2096 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 330 T2096 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 331 T2096 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774
[junit4:junit4] 2> 331 T2096 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774/solr.xml
[junit4:junit4] 2> 332 T2096 oasc.CoreContainer.<init> New CoreContainer 494110180
[junit4:junit4] 2> 332 T2096 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774/'
[junit4:junit4] 2> 333 T2096 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774/'
[junit4:junit4] 2> 360 T2096 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 360 T2096 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 361 T2096 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 361 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 362 T2096 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 362 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 363 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 363 T2096 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 364 T2096 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 364 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 376 T2096 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 399 T2096 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:34660/solr
[junit4:junit4] 2> 399 T2096 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 400 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d8dbb6a
[junit4:junit4] 2> 401 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 401 T2115 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 402 T2115 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 402 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38130
[junit4:junit4] 2> 402 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38130
[junit4:junit4] 2> 403 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0002 with negotiated timeout 20000 for client /127.0.0.1:38130
[junit4:junit4] 2> 403 T2115 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0002, negotiated timeout = 20000
[junit4:junit4] 2> 403 T2116 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d8dbb6a name:ZooKeeperConnection Watcher:127.0.0.1:34660 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 404 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 405 T2101 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d3c0c016a0002
[junit4:junit4] 2> 405 T2098 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38130 which had sessionid 0x13d3c0c016a0002
[junit4:junit4] 2> 406 T2116 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 406 T2096 oaz.ZooKeeper.close Session: 0x13d3c0c016a0002 closed
[junit4:junit4] 2> 406 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 411 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d8eb111
[junit4:junit4] 2> 412 T2117 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 412 T2117 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 412 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38131
[junit4:junit4] 2> 413 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38131
[junit4:junit4] 2> 413 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0003 with negotiated timeout 20000 for client /127.0.0.1:38131
[junit4:junit4] 2> 414 T2117 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0003, negotiated timeout = 20000
[junit4:junit4] 2> 414 T2118 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d8eb111 name:ZooKeeperConnection Watcher:127.0.0.1:34660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 414 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 415 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 416 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 417 T2096 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 419 T2096 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55620_f_%2Ff
[junit4:junit4] 2> 423 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:55620_f_%2Ff Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:55620_f_%2Ff
[junit4:junit4] 2> 424 T2096 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55620_f_%2Ff
[junit4:junit4] 2> 426 T2096 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 429 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 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> 430 T2096 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 433 T2096 oasc.Overseer.start Overseer (id=89293589878276099-127.0.0.1:55620_f_%2Ff-n_0000000000) starting
[junit4:junit4] 2> 433 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 434 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 435 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 436 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 438 T2120 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 438 T2096 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 441 T2096 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 447 T2121 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774/collection1
[junit4:junit4] 2> 447 T2119 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 447 T2121 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 448 T2121 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 448 T2121 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 449 T2121 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774/collection1/'
[junit4:junit4] 2> 450 T2121 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774/collection1/lib/README' to classloader
[junit4:junit4] 2> 450 T2121 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 498 T2121 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 568 T2121 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 569 T2121 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 579 T2121 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1235 T2121 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1242 T2121 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1245 T2121 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1259 T2121 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1264 T2121 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1269 T2121 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1270 T2121 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1270 T2121 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1270 T2121 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1272 T2121 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1272 T2121 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1272 T2121 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1362512052774/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data/
[junit4:junit4] 2> 1273 T2121 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c3c9990
[junit4:junit4] 2> 1273 T2121 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1274 T2121 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data forceNew:false
[junit4:junit4] 2> 1274 T2121 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data
[junit4:junit4] 2> 1274 T2121 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data/index/
[junit4:junit4] 2> 1275 T2121 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1275 T2121 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data/index forceNew:false
[junit4:junit4] 2> 1277 T2121 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1dae607c lockFactory=org.apache.lucene.store.NativeFSLockFactory@1dae673f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1278 T2121 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1278 T2121 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data/index
[junit4:junit4] 2> 1280 T2121 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1280 T2121 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1281 T2121 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1281 T2121 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1282 T2121 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1282 T2121 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1283 T2121 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1283 T2121 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1284 T2121 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1287 T2121 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1291 T2121 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data
[junit4:junit4] 2> 1291 T2121 oass.SolrIndexSearcher.<init> Opening Searcher@1db844dc main
[junit4:junit4] 2> 1292 T2121 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data/tlog
[junit4:junit4] 2> 1292 T2121 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1293 T2121 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1297 T2121 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data
[junit4:junit4] 2> 1298 T2122 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1db844dc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1299 T2121 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1299 T2121 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1300 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 1950 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1951 T2119 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:55620_f_%2Ff",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55620/f_/f"}
[junit4:junit4] 2> 1951 T2119 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1951 T2119 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 1952 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 1955 T2118 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> 2051 T567 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4] 2> 2302 T2121 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2302 T2121 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55620/f_/f collection:control_collection shard:shard1
[junit4:junit4] 2> 2303 T2121 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2308 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:delete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 2308 T2121 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2309 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2310 T2121 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2310 T2121 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2311 T2121 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55620/f_/f/collection1/
[junit4:junit4] 2> 2311 T2121 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2311 T2121 oasc.SyncStrategy.syncToMe http://127.0.0.1:55620/f_/f/collection1/ has no replicas
[junit4:junit4] 2> 2311 T2121 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55620/f_/f/collection1/
[junit4:junit4] 2> 2312 T2121 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2314 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3458 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3474 T2118 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> 3518 T2121 oasc.ZkController.register We are http://127.0.0.1:55620/f_/f/collection1/ and leader is http://127.0.0.1:55620/f_/f/collection1/
[junit4:junit4] 2> 3518 T2121 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55620/f_/f
[junit4:junit4] 2> 3518 T2121 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3518 T2121 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3519 T2121 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3520 T2121 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3521 T2096 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 3522 T2096 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3522 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3525 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3526 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1dba6b31
[junit4:junit4] 2> 3526 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3527 T2124 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 3527 T2124 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 3527 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38139
[junit4:junit4] 2> 3527 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38139
[junit4:junit4] 2> 3528 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0004 with negotiated timeout 10000 for client /127.0.0.1:38139
[junit4:junit4] 2> 3528 T2124 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0004, negotiated timeout = 10000
[junit4:junit4] 2> 3528 T2125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dba6b31 name:ZooKeeperConnection Watcher:127.0.0.1:34660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3528 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3529 T2096 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3530 T2096 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 3604 T2096 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 3605 T2096 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58959
[junit4:junit4] 2> 3606 T2096 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 3607 T2096 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3607 T2096 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083
[junit4:junit4] 2> 3608 T2096 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083/solr.xml
[junit4:junit4] 2> 3608 T2096 oasc.CoreContainer.<init> New CoreContainer 498412468
[junit4:junit4] 2> 3609 T2096 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083/'
[junit4:junit4] 2> 3609 T2096 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083/'
[junit4:junit4] 2> 3628 T2096 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 3628 T2096 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 3629 T2096 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 3629 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 3629 T2096 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 3629 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 3630 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 3630 T2096 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 3630 T2096 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3631 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 3638 T2096 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 3658 T2096 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:34660/solr
[junit4:junit4] 2> 3658 T2096 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 3658 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c25f4ab
[junit4:junit4] 2> 3659 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3659 T2135 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 3660 T2135 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 3660 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38140
[junit4:junit4] 2> 3660 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38140
[junit4:junit4] 2> 3661 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0005 with negotiated timeout 20000 for client /127.0.0.1:38140
[junit4:junit4] 2> 3661 T2135 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0005, negotiated timeout = 20000
[junit4:junit4] 2> 3661 T2136 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c25f4ab name:ZooKeeperConnection Watcher:127.0.0.1:34660 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3661 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3662 T2101 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d3c0c016a0005
[junit4:junit4] 2> 3662 T2136 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 3662 T2096 oaz.ZooKeeper.close Session: 0x13d3c0c016a0005 closed
[junit4:junit4] 2> 3662 T2098 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38140 which had sessionid 0x13d3c0c016a0005
[junit4:junit4] 2> 3663 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 3666 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c271b32
[junit4:junit4] 2> 3666 T2137 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 3666 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3667 T2137 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 3667 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38141
[junit4:junit4] 2> 3667 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38141
[junit4:junit4] 2> 3668 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0006 with negotiated timeout 20000 for client /127.0.0.1:38141
[junit4:junit4] 2> 3668 T2137 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0006, negotiated timeout = 20000
[junit4:junit4] 2> 3668 T2138 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c271b32 name:ZooKeeperConnection Watcher:127.0.0.1:34660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3668 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3669 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3669 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3670 T2096 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3765 T577 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4] 2> 4671 T2096 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58959_f_%2Ff
[junit4:junit4] 2> 4672 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:58959_f_%2Ff Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:58959_f_%2Ff
[junit4:junit4] 2> 4672 T2096 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58959_f_%2Ff
[junit4:junit4] 2> 4674 T2125 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4674 T2118 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4674 T2118 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> 4674 T2138 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4679 T2139 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083/collection1
[junit4:junit4] 2> 4679 T2139 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 4680 T2139 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 4680 T2139 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 4681 T2139 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083/collection1/'
[junit4:junit4] 2> 4681 T2139 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083/collection1/lib/README' to classloader
[junit4:junit4] 2> 4681 T2139 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 4710 T2139 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 4753 T2139 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 4754 T2139 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 4760 T2139 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 4978 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4979 T2119 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:55620_f_%2Ff",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55620/f_/f"}
[junit4:junit4] 2> 4982 T2125 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> 4982 T2138 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> 4982 T2118 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> 5240 T2139 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 5247 T2139 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5250 T2139 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5259 T2139 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5262 T2139 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5265 T2139 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5266 T2139 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5267 T2139 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5267 T2139 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5268 T2139 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5268 T2139 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5268 T2139 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1362512056083/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1/
[junit4:junit4] 2> 5268 T2139 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c3c9990
[junit4:junit4] 2> 5269 T2139 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5269 T2139 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1 forceNew:false
[junit4:junit4] 2> 5269 T2139 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1
[junit4:junit4] 2> 5269 T2139 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1/index/
[junit4:junit4] 2> 5270 T2139 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5270 T2139 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1/index forceNew:false
[junit4:junit4] 2> 5271 T2139 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c8ff5f6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c8ffcb9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 5271 T2139 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 5272 T2139 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1/index
[junit4:junit4] 2> 5273 T2139 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 5273 T2139 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 5273 T2139 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 5274 T2139 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 5274 T2139 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 5274 T2139 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 5275 T2139 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 5276 T2139 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 5277 T2139 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 5279 T2139 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 5281 T2139 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1
[junit4:junit4] 2> 5282 T2139 oass.SolrIndexSearcher.<init> Opening Searcher@1c9ad6a0 main
[junit4:junit4] 2> 5282 T2139 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1/tlog
[junit4:junit4] 2> 5282 T2139 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 5283 T2139 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 5287 T2140 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c9ad6a0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5289 T2139 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5289 T2139 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 5479 T585 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4] 2> 6485 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6485 T2119 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:58959_f_%2Ff",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58959/f_/f"}
[junit4:junit4] 2> 6486 T2119 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 6486 T2119 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 6490 T2125 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> 6490 T2138 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> 6490 T2118 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> 7188 T593 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4] 2> 7290 T2139 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7290 T2139 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58959/f_/f collection:collection1 shard:shard1
[junit4:junit4] 2> 7291 T2139 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 7298 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0006 type:delete cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 7299 T2139 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7299 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7304 T2139 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7304 T2139 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7305 T2139 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58959/f_/f/collection1/
[junit4:junit4] 2> 7305 T2139 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7305 T2139 oasc.SyncStrategy.syncToMe http://127.0.0.1:58959/f_/f/collection1/ has no replicas
[junit4:junit4] 2> 7305 T2139 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58959/f_/f/collection1/
[junit4:junit4] 2> 7305 T2139 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 7307 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7994 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7999 T2118 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> 7999 T2125 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> 8000 T2138 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> 8010 T2139 oasc.ZkController.register We are http://127.0.0.1:58959/f_/f/collection1/ and leader is http://127.0.0.1:58959/f_/f/collection1/
[junit4:junit4] 2> 8010 T2139 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58959/f_/f
[junit4:junit4] 2> 8010 T2139 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8010 T2139 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8010 T2139 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8011 T2139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8012 T2096 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 8013 T2096 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8013 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8092 T2096 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8095 T2096 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42744
[junit4:junit4] 2> 8096 T2096 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8096 T2096 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8096 T2096 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571
[junit4:junit4] 2> 8097 T2096 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571/solr.xml
[junit4:junit4] 2> 8097 T2096 oasc.CoreContainer.<init> New CoreContainer 485238867
[junit4:junit4] 2> 8098 T2096 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571/'
[junit4:junit4] 2> 8099 T2096 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571/'
[junit4:junit4] 2> 8118 T2096 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8119 T2096 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8119 T2096 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8119 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8120 T2096 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8120 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8120 T2096 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8121 T2096 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8121 T2096 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8121 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8129 T2096 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8144 T2096 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:34660/solr
[junit4:junit4] 2> 8144 T2096 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8145 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d055ae2
[junit4:junit4] 2> 8145 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8146 T2151 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8146 T2151 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 8146 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38142
[junit4:junit4] 2> 8147 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38142
[junit4:junit4] 2> 8147 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0007 with negotiated timeout 20000 for client /127.0.0.1:38142
[junit4:junit4] 2> 8147 T2151 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0007, negotiated timeout = 20000
[junit4:junit4] 2> 8148 T2152 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d055ae2 name:ZooKeeperConnection Watcher:127.0.0.1:34660 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8148 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8149 T2101 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d3c0c016a0007
[junit4:junit4] 2> 8149 T2152 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8149 T2098 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:38142 which had sessionid 0x13d3c0c016a0007
[junit4:junit4] 2> 8149 T2096 oaz.ZooKeeper.close Session: 0x13d3c0c016a0007 closed
[junit4:junit4] 2> 8150 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8152 T2096 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:34660/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cab6bbf
[junit4:junit4] 2> 8153 T2096 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8153 T2153 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:34660. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8154 T2153 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:34660, initiating session
[junit4:junit4] 2> 8154 T2098 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:38143
[junit4:junit4] 2> 8154 T2098 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:38143
[junit4:junit4] 2> 8155 T2100 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d3c0c016a0008 with negotiated timeout 20000 for client /127.0.0.1:38143
[junit4:junit4] 2> 8155 T2153 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:34660, sessionid = 0x13d3c0c016a0008, negotiated timeout = 20000
[junit4:junit4] 2> 8155 T2154 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cab6bbf name:ZooKeeperConnection Watcher:127.0.0.1:34660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8155 T2096 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8156 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8156 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8157 T2096 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9159 T2096 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42744_f_%2Ff
[junit4:junit4] 2> 9160 T2101 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d3c0c016a0008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:42744_f_%2Ff Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:42744_f_%2Ff
[junit4:junit4] 2> 9160 T2096 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42744_f_%2Ff
[junit4:junit4] 2> 9162 T2138 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> 9163 T2125 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9163 T2118 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9163 T2125 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> 9163 T2118 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> 9163 T2154 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9164 T2138 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9168 T2155 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571/collection1
[junit4:junit4] 2> 9168 T2155 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9168 T2155 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9168 T2155 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9169 T2155 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571/collection1/'
[junit4:junit4] 2> 9170 T2155 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571/collection1/lib/README' to classloader
[junit4:junit4] 2> 9170 T2155 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9202 T2155 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 9245 T2155 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9246 T2155 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9251 T2155 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9504 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9504 T2119 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:58959_f_%2Ff",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58959/f_/f"}
[junit4:junit4] 2> 9507 T2118 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> 9507 T2138 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> 9507 T2154 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> 9508 T2125 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> 9692 T610 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4] 2> 9742 T2155 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 9749 T2155 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 9753 T2155 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 9762 T2155 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9765 T2155 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 9768 T2155 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9769 T2155 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 9769 T2155 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 9769 T2155 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 9770 T2155 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 9770 T2155 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 9770 T2155 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1362512060571/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/
[junit4:junit4] 2> 9770 T2155 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c3c9990
[junit4:junit4] 2> 9771 T2155 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 9771 T2155 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2 forceNew:false
[junit4:junit4] 2> 9771 T2155 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 9771 T2155 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index/
[junit4:junit4] 2> 9772 T2155 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 9772 T2155 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index forceNew:false
[junit4:junit4] 2> 9773 T2155 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c679f4b lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c67a60e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 9773 T2155 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 9774 T2155 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index
[junit4:junit4] 2> 9775 T2155 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 9775 T2155 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 9775 T2155 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 9776 T2155 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 9776 T2155 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 9776 T2155 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 9777 T2155 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 9777 T2155 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 9777 T2155 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 9779 T2155 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 9782 T2155 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 9782 T2155 oass.SolrIndexSearcher.<init> Opening Searcher@1c67d46d main
[junit4:junit4] 2> 9783 T2155 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/tlog
[junit4:junit4] 2> 9783 T2155 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 9783 T2155 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 9790 T2156 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c67d46d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 9792 T2155 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 9792 T2155 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11012 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11013 T2119 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42744_f_%2Ff",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42744/f_/f"}
[junit4:junit4] 2> 11013 T2119 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 11013 T2119 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 11020 T2138 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> 11020 T2154 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> 11020 T2118 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> 11020 T2125 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> 11431 T627 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4] 2> 11793 T2155 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 11794 T2155 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42744/f_/f collection:collection1 shard:shard1
[junit4:junit4] 2> 11797 T2155 oasc.ZkController.register We are http://127.0.0.1:42744/f_/f/collection1/ and leader is http://127.0.0.1:58959/f_/f/collection1/
[junit4:junit4] 2> 11797 T2155 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42744/f_/f
[junit4:junit4] 2> 11797 T2155 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 11797 T2155 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C101 name=collection1 org.apache.solr.core.SolrCore@1c5caaba url=http://127.0.0.1:42744/f_/f/collection1 node=127.0.0.1:42744_f_%2Ff C101_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:42744_f_%2Ff, base_url=http://127.0.0.1:42744/f_/f}
[junit4:junit4] 2> 11798 T2157 C101 P42744 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 11798 T2157 C101 P42744 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 11798 T2155 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11798 T2157 C101 P42744 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 11799 T2157 C101 P42744 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11799 T2096 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 11799 T2157 C101 P42744 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 11800 T2096 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 11800 T2096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 11805 T2096 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C102 name=collection1 org.apache.solr.core.SolrCore@1dadd693 url=http://127.0.0.1:55620/f_/f/collection1 node=127.0.0.1:55620_f_%2Ff C102_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:55620_f_%2Ff, base_url=http://127.0.0.1:55620/f_/f, leader=true}
[junit4:junit4] 2> 11815 T2112 C102 P55620 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/control/data
[junit4:junit4] 2> 11816 T2112 C102 P55620 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1dae607c lockFactory=org.apache.lucene.store.NativeFSLockFactory@1dae673f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 11816 T2112 C102 P55620 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 11818 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10001 (1428697450406739968)]} 0 3
[junit4:junit4] 2> 11821 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[1 (1428697450406739969)]} 0 6
[junit4:junit4] 2> ASYNC NEW_CORE C103 name=collection1 org.apache.solr.core.SolrCore@1c8f692d url=http://127.0.0.1:58959/f_/f/collection1 node=127.0.0.1:58959_f_%2Ff C103_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:58959_f_%2Ff, base_url=http://127.0.0.1:58959/f_/f, leader=true}
[junit4:junit4] 2> 11827 T2131 C103 P58959 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1
[junit4:junit4] 2> 11828 T2131 C103 P58959 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c8ff5f6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c8ffcb9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 11829 T2131 C103 P58959 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 11830 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10001 (1428697450419322880)]} 0 4
[junit4:junit4] 2> 11831 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[1 (1428697450421420032)]} 0 1
[junit4:junit4] 2> 11844 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[2 (1428697450437148672)]} 0 1
[junit4:junit4] 2> 11844 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10002 (1428697450437148673)]} 0 1
[junit4:junit4] 2> 11847 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[2 (1428697450439245824)]} 0 1
[junit4:junit4] 2> 11847 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10002 (1428697450439245825)]} 0 1
[junit4:junit4] 2> 11916 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[2 (-1428697450512646145)]} 0 0
[junit4:junit4] 2> 11916 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[10002 (-1428697450512646144)]} 0 0
[junit4:junit4] 2> 11918 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[10002 (-1428697450514743296)]} 0 0
[junit4:junit4] 2> 11919 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[2 (-1428697450515791872)]} 0 0
[junit4:junit4] 2> 11921 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10003 (1428697450516840448)]} 0 1
[junit4:junit4] 2> 11921 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[3 (1428697450517889024)]} 0 0
[junit4:junit4] 2> 11923 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10003 (1428697450519986176)]} 0 0
[junit4:junit4] 2> 11924 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[3 (1428697450519986177)]} 0 1
[junit4:junit4] 2> 11997 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10004 (1428697450596532224)]} 0 1
[junit4:junit4] 2> 11997 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[4 (1428697450597580800)]} 0 0
[junit4:junit4] 2> 12000 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10004 (1428697450599677952)]} 0 1
[junit4:junit4] 2> 12000 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[4 (1428697450599677953)]} 0 1
[junit4:junit4] 2> 12018 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10005 (1428697450619600896)]} 0 0
[junit4:junit4] 2> 12019 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[5 (1428697450619600897)]} 0 1
[junit4:junit4] 2> 12021 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10005 (1428697450621698048)]} 0 1
[junit4:junit4] 2> 12021 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[5 (1428697450621698049)]} 0 1
[junit4:junit4] 2> 12091 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10006 (1428697450696146944)]} 0 0
[junit4:junit4] 2> 12091 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[6 (1428697450696146945)]} 0 0
[junit4:junit4] 2> 12094 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10006 (1428697450698244096)]} 0 1
[junit4:junit4] 2> 12094 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[6 (1428697450699292672)]} 0 1
[junit4:junit4] 2> 12106 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10007 (1428697450710827008)]} 0 1
[junit4:junit4] 2> 12106 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[7 (1428697450710827009)]} 0 1
[junit4:junit4] 2> 12108 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10007 (1428697450713972736)]} 0 0
[junit4:junit4] 2> 12108 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[7 (1428697450713972737)]} 0 0
[junit4:junit4] 2> 12207 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10008 (1428697450816733184)]} 0 1
[junit4:junit4] 2> 12207 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[8 (1428697450817781760)]} 0 1
[junit4:junit4] 2> 12209 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10008 (1428697450819878912)]} 0 0
[junit4:junit4] 2> 12210 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[8 (1428697450819878913)]} 0 1
[junit4:junit4] 2> 12238 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10009 (1428697450850287616)]} 0 0
[junit4:junit4] 2> 12239 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[9 (1428697450850287617)]} 0 1
[junit4:junit4] 2> 12241 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10009 (1428697450852384768)]} 0 1
[junit4:junit4] 2> 12241 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[9 (1428697450852384769)]} 0 1
[junit4:junit4] 2> 12259 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[10003 (-1428697450872307712)]} 0 0
[junit4:junit4] 2> 12259 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[3 (-1428697450872307713)]} 0 0
[junit4:junit4] 2> 12261 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[10003 (-1428697450874404864)]} 0 0
[junit4:junit4] 2> 12261 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[3 (-1428697450874404865)]} 0 0
[junit4:junit4] 2> 12263 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10010 (1428697450876502016)]} 0 0
[junit4:junit4] 2> 12264 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10 (1428697450876502017)]} 0 1
[junit4:junit4] 2> 12265 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10010 (1428697450878599168)]} 0 0
[junit4:junit4] 2> 12266 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10 (1428697450878599169)]} 0 1
[junit4:junit4] 2> 12328 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10011 (1428697450944659456)]} 0 0
[junit4:junit4] 2> 12328 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[11 (1428697450944659457)]} 0 0
[junit4:junit4] 2> 12331 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10011 (1428697450947805184)]} 0 1
[junit4:junit4] 2> 12332 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[11 (1428697450947805185)]} 0 1
[junit4:junit4] 2> 12341 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10012 (1428697450957242368)]} 0 1
[junit4:junit4] 2> 12341 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[12 (1428697450958290944)]} 0 1
[junit4:junit4] 2> 12344 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10012 (1428697450960388096)]} 0 1
[junit4:junit4] 2> 12344 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[12 (1428697450960388097)]} 0 1
[junit4:junit4] 2> 12384 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10013 (1428697451002331136)]} 0 1
[junit4:junit4] 2> 12384 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[13 (1428697451002331137)]} 0 1
[junit4:junit4] 2> 12386 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10013 (1428697451005476864)]} 0 0
[junit4:junit4] 2> 12387 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[13 (1428697451005476865)]} 0 1
[junit4:junit4] 2> 12389 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10014 (1428697451007574016)]} 0 1
[junit4:junit4] 2> 12389 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[14 (1428697451008622592)]} 0 0
[junit4:junit4] 2> 12391 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10014 (1428697451010719744)]} 0 0
[junit4:junit4] 2> 12392 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[14 (1428697451010719745)]} 0 1
[junit4:junit4] 2> 12400 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10015 (1428697451019108352)]} 0 1
[junit4:junit4] 2> 12400 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[15 (1428697451019108353)]} 0 1
[junit4:junit4] 2> 12403 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10015 (1428697451022254080)]} 0 1
[junit4:junit4] 2> 12403 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[15 (1428697451022254081)]} 0 1
[junit4:junit4] 2> 12416 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[16 (1428697451035885568)]} 0 1
[junit4:junit4] 2> 12416 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10016 (1428697451036934144)]} 0 0
[junit4:junit4] 2> 12418 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[16 (1428697451039031296)]} 0 0
[junit4:junit4] 2> 12418 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10016 (1428697451039031297)]} 0 0
[junit4:junit4] 2> 12469 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[17 (1428697451091460096)]} 0 1
[junit4:junit4] 2> 12469 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10017 (1428697451092508672)]} 0 0
[junit4:junit4] 2> 12471 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[17 (1428697451094605824)]} 0 0
[junit4:junit4] 2> 12472 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10017 (1428697451094605825)]} 0 1
[junit4:junit4] 2> 12524 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12525 T2119 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42744_f_%2Ff",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42744/f_/f"}
[junit4:junit4] 2> 12528 T2118 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> 12528 T2154 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> 12528 T2138 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> 12528 T2125 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> 12552 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10018 (1428697451179540481)]} 0 0
[junit4:junit4] 2> 12553 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[18 (1428697451179540480)]} 0 1
[junit4:junit4] 2> C101_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:42744_f_%2Ff, base_url=http://127.0.0.1:42744/f_/f}
[junit4:junit4] 2> 12560 T2149 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 12562 T2149 C101 P42744 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c679f4b lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c67a60e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 12562 T2149 C101 P42744 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 12564 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1428697451181637633)]} 0 4
[junit4:junit4] 2> 12564 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10018 (1428697451181637632)]} 0 4
[junit4:junit4] 2> 12564 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[18 (1428697451181637633)]} 0 10
[junit4:junit4] 2> 12565 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10018 (1428697451181637632)]} 0 11
[junit4:junit4] 2> 12583 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[4 (-1428697451212046336)]} 0 0
[junit4:junit4] 2> 12584 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[10004 (-1428697451213094912)]} 0 0
[junit4:junit4] 2> 12587 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10004 (-1428697451215192065)]} 0 0
[junit4:junit4] 2> 12588 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[4 (-1428697451215192064)]} 0 1
[junit4:junit4] 2> 12588 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[10004 (-1428697451215192065)]} 0 2
[junit4:junit4] 2> 12588 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[4 (-1428697451215192064)]} 0 3
[junit4:junit4] 2> 12590 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10019 (1428697451219386368)]} 0 0
[junit4:junit4] 2> 12591 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[19 (1428697451219386369)]} 0 1
[junit4:junit4] 2> 12595 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10019 (1428697451222532096)]} 0 0
[junit4:junit4] 2> 12595 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1428697451222532097)]} 0 0
[junit4:junit4] 2> 12596 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10019 (1428697451222532096)]} 0 4
[junit4:junit4] 2> 12596 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[19 (1428697451222532097)]} 0 3
[junit4:junit4] 2> 12668 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[10005 (-1428697451301175297)]} 0 0
[junit4:junit4] 2> 12668 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[5 (-1428697451301175296)]} 0 0
[junit4:junit4] 2> 12672 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10005 (-1428697451303272448)]} 0 0
[junit4:junit4] 2> 12672 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[5 (-1428697451303272449)]} 0 0
[junit4:junit4] 2> 12672 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10005 (-1428697451303272448)]} 0 2
[junit4:junit4] 2> 12673 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[5 (-1428697451303272449)]} 0 3
[junit4:junit4] 2> 12675 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10020 (1428697451307466752)]} 0 1
[junit4:junit4] 2> 12675 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[20 (1428697451307466753)]} 0 1
[junit4:junit4] 2> 12679 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10020 (1428697451310612480)]} 0 0
[junit4:junit4] 2> 12679 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10020 (1428697451310612480)]} 0 2
[junit4:junit4] 2> 12680 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1428697451310612481)]} 0 0
[junit4:junit4] 2> 12680 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[20 (1428697451310612481)]} 0 3
[junit4:junit4] 2> 12721 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10021 (1428697451356749824)]} 0 0
[junit4:junit4] 2> 12722 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[21 (1428697451356749825)]} 0 1
[junit4:junit4] 2> 12726 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10021 (1428697451358846976)]} 0 1
[junit4:junit4] 2> 12727 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1428697451359895552)]} 0 1
[junit4:junit4] 2> 12727 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10021 (1428697451358846976)]} 0 4
[junit4:junit4] 2> 12727 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[21 (1428697451359895552)]} 0 3
[junit4:junit4] 2> 12729 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10022 (1428697451365138432)]} 0 0
[junit4:junit4] 2> 12729 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[22 (1428697451365138433)]} 0 0
[junit4:junit4] 2> 12733 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10022 (1428697451367235584)]} 0 0
[junit4:junit4] 2> 12733 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1428697451367235585)]} 0 0
[junit4:junit4] 2> 12734 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10022 (1428697451367235584)]} 0 3
[junit4:junit4] 2> 12734 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[22 (1428697451367235585)]} 0 3
[junit4:junit4] 2> 12772 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[23 (1428697451409178624)]} 0 1
[junit4:junit4] 2> 12772 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10023 (1428697451409178625)]} 0 1
[junit4:junit4] 2> 12777 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1428697451412324352)]} 0 1
[junit4:junit4] 2> 12777 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10023 (1428697451412324353)]} 0 1
[junit4:junit4] 2> 12777 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[23 (1428697451412324352)]} 0 3
[junit4:junit4] 2> 12777 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10023 (1428697451412324353)]} 0 3
[junit4:junit4] 2> 12786 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[7 (-1428697451424907264)]} 0 0
[junit4:junit4] 2> 12786 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[10007 (-1428697451424907265)]} 0 0
[junit4:junit4] 2> 12790 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[7 (-1428697451427004416)]} 0 1
[junit4:junit4] 2> 12790 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10007 (-1428697451427004417)]} 0 0
[junit4:junit4] 2> 12790 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[7 (-1428697451427004416)]} 0 2
[junit4:junit4] 2> 12790 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[10007 (-1428697451427004417)]} 0 2
[junit4:junit4] 2> 12792 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[24 (1428697451431198720)]} 0 0
[junit4:junit4] 2> 12792 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10024 (1428697451431198721)]} 0 0
[junit4:junit4] 2> 12796 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1428697451433295872)]} 0 0
[junit4:junit4] 2> 12797 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10024 (1428697451433295873)]} 0 0
[junit4:junit4] 2> 12797 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[24 (1428697451433295872)]} 0 3
[junit4:junit4] 2> 12797 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10024 (1428697451433295873)]} 0 3
[junit4:junit4] 2> 12814 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10011 (-1428697451454267392)]} 0 0
[junit4:junit4] 2> 12814 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[11 (-1428697451454267393)]} 0 0
[junit4:junit4] 2> 12817 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10011 (-1428697451456364544)]} 0 0
[junit4:junit4] 2> 12818 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[11 (-1428697451456364545)]} 0 0
[junit4:junit4] 2> 12818 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10011 (-1428697451456364544)]} 0 2
[junit4:junit4] 2> 12819 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[11 (-1428697451456364545)]} 0 3
[junit4:junit4] 2> 12821 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10025 (1428697451460558848)]} 0 1
[junit4:junit4] 2> 12821 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[25 (1428697451461607424)]} 0 0
[junit4:junit4] 2> 12825 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10025 (1428697451463704576)]} 0 0
[junit4:junit4] 2> 12826 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1428697451463704577)]} 0 1
[junit4:junit4] 2> 12826 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10025 (1428697451463704576)]} 0 3
[junit4:junit4] 2> 12826 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[25 (1428697451463704577)]} 0 3
[junit4:junit4] 2> 12857 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10026 (1428697451498307584)]} 0 1
[junit4:junit4] 2> 12857 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[26 (1428697451498307585)]} 0 1
[junit4:junit4] 2> 12861 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10026 (1428697451501453312)]} 0 0
[junit4:junit4] 2> 12861 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1428697451501453313)]} 0 0
[junit4:junit4] 2> 12861 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10026 (1428697451501453312)]} 0 2
[junit4:junit4] 2> 12862 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[26 (1428697451501453313)]} 0 3
[junit4:junit4] 2> 12963 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[10012 (-1428697451609456640)]} 0 1
[junit4:junit4] 2> 12963 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[12 (-1428697451610505216)]} 0 0
[junit4:junit4] 2> 12966 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10012 (-1428697451611553792)]} 0 0
[junit4:junit4] 2> 12966 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[12 (-1428697451612602368)]} 0 0
[junit4:junit4] 2> 12966 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[10012 (-1428697451611553792)]} 0 2
[junit4:junit4] 2> 12967 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[12 (-1428697451612602368)]} 0 2
[junit4:junit4] 2> 12969 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10027 (1428697451615748096)]} 0 1
[junit4:junit4] 2> 12969 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[27 (1428697451615748097)]} 0 1
[junit4:junit4] 2> 12972 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10027 (1428697451617845248)]} 0 0
[junit4:junit4] 2> 12973 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10027 (1428697451617845248)]} 0 3
[junit4:junit4] 2> 12973 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1428697451618893824)]} 0 1
[junit4:junit4] 2> 12974 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[27 (1428697451618893824)]} 0 4
[junit4:junit4] 2> 12998 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10028 (1428697451647205376)]} 0 0
[junit4:junit4] 2> 12999 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[28 (1428697451647205377)]} 0 1
[junit4:junit4] 2> 13002 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10028 (1428697451649302528)]} 0 0
[junit4:junit4] 2> 13003 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10028 (1428697451649302528)]} 0 3
[junit4:junit4] 2> 13003 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1428697451650351104)]} 0 0
[junit4:junit4] 2> 13004 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[28 (1428697451650351104)]} 0 3
[junit4:junit4] 2> 13011 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10013 (-1428697451660836864)]} 0 0
[junit4:junit4] 2> 13011 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[13 (-1428697451660836865)]} 0 0
[junit4:junit4] 2> 13014 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10013 (-1428697451662934016)]} 0 0
[junit4:junit4] 2> 13014 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10013 (-1428697451662934016)]} 0 2
[junit4:junit4] 2> 13015 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[13 (-1428697451662934017)]} 0 1
[junit4:junit4] 2> 13015 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[13 (-1428697451662934017)]} 0 2
[junit4:junit4] 2> 13017 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10029 (1428697451666079744)]} 0 1
[junit4:junit4] 2> 13017 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[29 (1428697451667128320)]} 0 0
[junit4:junit4] 2> 13020 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10029 (1428697451668176896)]} 0 0
[junit4:junit4] 2> 13021 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10029 (1428697451668176896)]} 0 3
[junit4:junit4] 2> 13021 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1428697451669225472)]} 0 0
[junit4:junit4] 2> 13021 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[29 (1428697451669225472)]} 0 2
[junit4:junit4] 2> 13067 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10014 (-1428697451719557120)]} 0 0
[junit4:junit4] 2> 13067 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[14 (-1428697451719557121)]} 0 0
[junit4:junit4] 2> 13071 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10014 (-1428697451721654272)]} 0 1
[junit4:junit4] 2> 13071 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[14 (-1428697451721654273)]} 0 1
[junit4:junit4] 2> 13071 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10014 (-1428697451721654272)]} 0 2
[junit4:junit4] 2> 13071 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[14 (-1428697451721654273)]} 0 2
[junit4:junit4] 2> 13073 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10030 (1428697451725848576)]} 0 0
[junit4:junit4] 2> 13074 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[30 (1428697451725848577)]} 0 1
[junit4:junit4] 2> 13078 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10030 (1428697451727945728)]} 0 1
[junit4:junit4] 2> 13078 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1428697451728994304)]} 0 0
[junit4:junit4] 2> 13079 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10030 (1428697451727945728)]} 0 4
[junit4:junit4] 2> 13079 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[30 (1428697451728994304)]} 0 4
[junit4:junit4] 2> 13084 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[31 (1428697451737382912)]} 0 0
[junit4:junit4] 2> 13085 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10031 (1428697451736334336)]} 0 2
[junit4:junit4] 2> 13088 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1428697451739480064)]} 0 0
[junit4:junit4] 2> 13089 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10031 (1428697451739480065)]} 0 1
[junit4:junit4] 2> 13089 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[31 (1428697451739480064)]} 0 3
[junit4:junit4] 2> 13090 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10031 (1428697451739480065)]} 0 4
[junit4:junit4] 2> 13174 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[18 (-1428697451831754752)]} 0 0
[junit4:junit4] 2> 13174 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10018 (-1428697451831754753)]} 0 0
[junit4:junit4] 2> 13178 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[18 (-1428697451833851904)]} 0 0
[junit4:junit4] 2> 13178 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10018 (-1428697451833851905)]} 0 0
[junit4:junit4] 2> 13178 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[18 (-1428697451833851904)]} 0 2
[junit4:junit4] 2> 13179 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[10018 (-1428697451833851905)]} 0 3
[junit4:junit4] 2> 13181 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[32 (1428697451839094784)]} 0 0
[junit4:junit4] 2> 13182 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10032 (1428697451839094785)]} 0 1
[junit4:junit4] 2> 13185 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1428697451841191936)]} 0 0
[junit4:junit4] 2> 13186 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[32 (1428697451841191936)]} 0 3
[junit4:junit4] 2> 13186 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10032 (1428697451841191937)]} 0 1
[junit4:junit4] 2> 13186 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10032 (1428697451841191937)]} 0 3
[junit4:junit4] 2> 13275 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[33 (1428697451937660928)]} 0 0
[junit4:junit4] 2> 13276 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10033 (1428697451937660929)]} 0 1
[junit4:junit4] 2> 13280 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1428697451940806656)]} 0 1
[junit4:junit4] 2> 13280 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[33 (1428697451940806656)]} 0 2
[junit4:junit4] 2> 13280 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10033 (1428697451940806657)]} 0 0
[junit4:junit4] 2> 13281 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10033 (1428697451940806657)]} 0 3
[junit4:junit4] 2> 13294 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[34 (1428697451956535296)]} 0 1
[junit4:junit4] 2> 13294 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10034 (1428697451957583872)]} 0 0
[junit4:junit4] 2> 13298 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1428697451959681024)]} 0 1
[junit4:junit4] 2> 13298 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10034 (1428697451959681025)]} 0 0
[junit4:junit4] 2> 13299 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[34 (1428697451959681024)]} 0 4
[junit4:junit4] 2> 13299 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10034 (1428697451959681025)]} 0 3
[junit4:junit4] 2> 13331 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10035 (1428697451996381185)]} 0 0
[junit4:junit4] 2> 13331 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[35 (1428697451996381184)]} 0 0
[junit4:junit4] 2> 13336 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10035 (1428697451998478336)]} 0 1
[junit4:junit4] 2> 13336 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1428697451998478337)]} 0 0
[junit4:junit4] 2> 13337 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10035 (1428697451998478336)]} 0 4
[junit4:junit4] 2> 13337 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[35 (1428697451998478337)]} 0 4
[junit4:junit4] 2> 13355 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10036 (1428697452021547008)]} 0 0
[junit4:junit4] 2> 13355 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[36 (1428697452021547009)]} 0 0
[junit4:junit4] 2> 13360 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10036 (1428697452023644160)]} 0 1
[junit4:junit4] 2> 13360 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1428697452023644161)]} 0 0
[junit4:junit4] 2> 13360 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10036 (1428697452023644160)]} 0 3
[junit4:junit4] 2> 13361 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[36 (1428697452023644161)]} 0 4
[junit4:junit4] 2> 13435 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10037 (1428697452104384512)]} 0 1
[junit4:junit4] 2> 13435 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[37 (1428697452105433088)]} 0 0
[junit4:junit4] 2> 13439 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10037 (1428697452107530240)]} 0 0
[junit4:junit4] 2> 13439 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10037 (1428697452107530240)]} 0 2
[junit4:junit4] 2> 13439 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1428697452107530241)]} 0 0
[junit4:junit4] 2> 13440 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[37 (1428697452107530241)]} 0 3
[junit4:junit4] 2> 13483 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[10019 (-1428697452155764736)]} 0 1
[junit4:junit4] 2> 13483 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[19 (-1428697452155764737)]} 0 0
[junit4:junit4] 2> 13486 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10019 (-1428697452157861888)]} 0 0
[junit4:junit4] 2> 13486 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[19 (-1428697452157861889)]} 0 0
[junit4:junit4] 2> 13487 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[10019 (-1428697452157861888)]} 0 2
[junit4:junit4] 2> 13487 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[19 (-1428697452157861889)]} 0 2
[junit4:junit4] 2> 13489 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10038 (1428697452162056192)]} 0 1
[junit4:junit4] 2> 13489 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[38 (1428697452162056193)]} 0 0
[junit4:junit4] 2> 13493 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10038 (1428697452164153344)]} 0 0
[junit4:junit4] 2> 13493 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1428697452164153345)]} 0 0
[junit4:junit4] 2> 13493 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10038 (1428697452164153344)]} 0 2
[junit4:junit4] 2> 13494 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[38 (1428697452164153345)]} 0 3
[junit4:junit4] 2> 13523 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10039 (1428697452197707776)]} 0 1
[junit4:junit4] 2> 13523 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[39 (1428697452197707777)]} 0 0
[junit4:junit4] 2> 13527 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10039 (1428697452199804928)]} 0 0
[junit4:junit4] 2> 13527 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1428697452199804929)]} 0 0
[junit4:junit4] 2> 13528 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10039 (1428697452199804928)]} 0 3
[junit4:junit4] 2> 13528 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[39 (1428697452199804929)]} 0 3
[junit4:junit4] 2> 13620 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10040 (1428697452299419648)]} 0 0
[junit4:junit4] 2> 13620 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[40 (1428697452299419649)]} 0 0
[junit4:junit4] 2> 13625 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10040 (1428697452301516800)]} 0 1
[junit4:junit4] 2> 13625 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1428697452302565376)]} 0 0
[junit4:junit4] 2> 13625 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10040 (1428697452301516800)]} 0 3
[junit4:junit4] 2> 13626 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[40 (1428697452302565376)]} 0 2
[junit4:junit4] 2> 13692 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10041 (1428697452373868544)]} 0 1
[junit4:junit4] 2> 13692 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[41 (1428697452374917120)]} 0 1
[junit4:junit4] 2> 13696 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10041 (1428697452377014272)]} 0 0
[junit4:junit4] 2> 13696 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1428697452377014273)]} 0 0
[junit4:junit4] 2> 13697 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10041 (1428697452377014272)]} 0 3
[junit4:junit4] 2> 13697 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[41 (1428697452377014273)]} 0 3
[junit4:junit4] 2> 13791 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[42 (1428697452478726144)]} 0 0
[junit4:junit4] 2> 13791 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10042 (1428697452478726145)]} 0 0
[junit4:junit4] 2> 13796 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[42 (1428697452480823296)]} 0 1
[junit4:junit4] 2> 13796 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10042 (1428697452480823297)]} 0 1
[junit4:junit4] 2> 13796 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[42 (1428697452480823296)]} 0 3
[junit4:junit4] 2> 13796 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10042 (1428697452480823297)]} 0 3
[junit4:junit4] 2> 13806 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[43 (1428697452493406208)]} 0 1
[junit4:junit4] 2> 13806 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10043 (1428697452493406209)]} 0 1
[junit4:junit4] 2> 13808 T2096 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 42744
[junit4:junit4] 2> 13809 T2096 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=485238867
[junit4:junit4] 2> 13811 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[43 (1428697452496551936)]} 0 1
[junit4:junit4] 2> 13811 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[43 (1428697452496551936)]} 0 3
[junit4:junit4] 2> 13811 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10043 (1428697452497600512)]} 0 0
[junit4:junit4] 2> 13812 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10043 (1428697452497600512)]} 0 3
[junit4:junit4] 2> 13856 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[44 (1428697452545835008)]} 0 1
[junit4:junit4] 2> 13857 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10044 (1428697452546883584)]} 0 1
[junit4:junit4] 2> 13860 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[44 (1428697452548980736)]} 0 0
[junit4:junit4] 2> 13861 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10044 (1428697452548980737)]} 0 1
[junit4:junit4] 2> 13861 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[44 (1428697452548980736)]} 0 3
[junit4:junit4] 2> 13861 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10044 (1428697452548980737)]} 0 3
[junit4:junit4] 2> 13884 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[45 (1428697452575195136)]} 0 1
[junit4:junit4] 2> 13884 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10045 (1428697452575195137)]} 0 1
[junit4:junit4] 2> 13888 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10045 (1428697452578340864)]} 0 0
[junit4:junit4] 2> 13888 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[45 (1428697452577292288)]} 0 1
[junit4:junit4] 2> 13888 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10045 (1428697452578340864)]} 0 2
[junit4:junit4] 2> 13889 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[45 (1428697452577292288)]} 0 4
[junit4:junit4] 2> 13896 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10046 (1428697452587778048)]} 0 1
[junit4:junit4] 2> 13896 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[46 (1428697452588826624)]} 0 0
[junit4:junit4] 2> 13900 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10046 (1428697452590923776)]} 0 0
[junit4:junit4] 2> 13901 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[46 (1428697452590923777)]} 0 1
[junit4:junit4] 2> 13901 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10046 (1428697452590923776)]} 0 3
[junit4:junit4] 2> 13901 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[46 (1428697452590923777)]} 0 3
[junit4:junit4] 2> 13927 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[47 (1428697452621332480)]} 0 0
[junit4:junit4] 2> 13928 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10047 (1428697452621332481)]} 0 1
[junit4:junit4] 2> 13932 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[47 (1428697452623429632)]} 0 1
[junit4:junit4] 2> 13932 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10047 (1428697452624478208)]} 0 1
[junit4:junit4] 2> 13932 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[47 (1428697452623429632)]} 0 3
[junit4:junit4] 2> 13938 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10047 (1428697452624478208)]} 0 8
[junit4:junit4] 2> 14007 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10048 (1428697452705218561)]} 0 0
[junit4:junit4] 2> 14007 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[48 (1428697452705218560)]} 0 0
[junit4:junit4] 2> 14012 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10048 (1428697452707315712)]} 0 1
[junit4:junit4] 2> 14012 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10048 (1428697452707315712)]} 0 3
[junit4:junit4] 2> 14012 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[48 (1428697452708364288)]} 0 0
[junit4:junit4] 2> 14013 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[48 (1428697452708364288)]} 0 4
[junit4:junit4] 2> 14026 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10024 (-1428697452725141504)]} 0 0
[junit4:junit4] 2> 14027 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[24 (-1428697452726190080)]} 0 0
[junit4:junit4] 2> 14030 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[24 (-1428697452728287232)]} 0 0
[junit4:junit4] 2> 14030 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10024 (-1428697452727238656)]} 0 0
[junit4:junit4] 2> 14031 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[24 (-1428697452728287232)]} 0 2
[junit4:junit4] 2> 14031 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[10024 (-1428697452727238656)]} 0 3
[junit4:junit4] 2> 14032 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14033 T2119 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42744_f_%2Ff",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42744/f_/f"}
[junit4:junit4] 2> 14033 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[49 (1428697452731432960)]} 0 1
[junit4:junit4] 2> 14033 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10049 (1428697452732481536)]} 0 0
[junit4:junit4] 2> 14037 T2118 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> 14037 T2154 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> 14037 T2138 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> 14038 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[49 (1428697452734578688)]} 0 1
[junit4:junit4] 2> C101_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:42744_f_%2Ff, base_url=http://127.0.0.1:42744/f_/f}
[junit4:junit4] 2> 14038 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10049 (1428697452735627264)]} 0 0
[junit4:junit4] 2> 14037 T2125 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> 14039 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10049 (1428697452735627264)]} 0 3
[junit4:junit4] 2> 14042 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[49 (1428697452734578688)]} 0 7
[junit4:junit4] 2> 14049 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10028 (-1428697452749258752)]} 0 0
[junit4:junit4] 2> 14051 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[10028 (-1428697452751355904)]} 0 0
[junit4:junit4] 2> 14053 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[28 (-1428697452753453056)]} 0 0
[junit4:junit4] 2> 14053 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10050 (1428697452753453057)]} 0 0
[junit4:junit4] 2> 14055 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[28 (-1428697452755550208)]} 0 1
[junit4:junit4] 2> 14056 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10050 (1428697452755550209)]} 0 1
[junit4:junit4] 2> 14057 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[50 (1428697452756598784)]} 0 1
[junit4:junit4] 2> 14060 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[50 (1428697452759744512)]} 0 1
[junit4:junit4] 2> 14094 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10051 (1428697452795396096)]} 0 1
[junit4:junit4] 2> 14096 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10051 (1428697452798541824)]} 0 0
[junit4:junit4] 2> 14096 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[51 (1428697452798541824)]} 0 0
[junit4:junit4] 2> 14098 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[51 (1428697452800638976)]} 0 0
[junit4:junit4] 2> 14185 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10052 (1428697452891865088)]} 0 0
[junit4:junit4] 2> 14188 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[52 (1428697452893962240)]} 0 1
[junit4:junit4] 2> 14188 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10052 (1428697452893962240)]} 0 1
[junit4:junit4] 2> 14190 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[52 (1428697452897107968)]} 0 0
[junit4:junit4] 2> 14212 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10029 (-1428697452920176640)]} 0 0
[junit4:junit4] 2> 14214 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[29 (-1428697452922273792)]} 0 0
[junit4:junit4] 2> 14214 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[10029 (-1428697452922273792)]} 0 0
[junit4:junit4] 2> 14216 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[29 (-1428697452924370944)]} 0 0
[junit4:junit4] 2> 14216 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10053 (1428697452924370944)]} 0 0
[junit4:junit4] 2> 14218 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[53 (1428697452926468096)]} 0 0
[junit4:junit4] 2> 14219 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10053 (1428697452926468096)]} 0 1
[junit4:junit4] 2> 14221 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[53 (1428697452928565248)]} 0 1
[junit4:junit4] 2> 14305 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10030 (-1428697453017694208)]} 0 0
[junit4:junit4] 2> 14307 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[10030 (-1428697453019791360)]} 0 0
[junit4:junit4] 2> 14307 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[30 (-1428697453019791360)]} 0 0
[junit4:junit4] 2> 14309 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[30 (-1428697453021888512)]} 0 0
[junit4:junit4] 2> 14309 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10054 (1428697453021888512)]} 0 0
[junit4:junit4] 2> 14311 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[54 (1428697453022937088)]} 0 1
[junit4:junit4] 2> 14311 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10054 (1428697453023985664)]} 0 0
[junit4:junit4] 2> 14313 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[54 (1428697453026082816)]} 0 1
[junit4:junit4] 2> 14370 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[10032 (-1428697453085851648)]} 0 1
[junit4:junit4] 2> 14371 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[32 (-1428697453086900224)]} 0 0
[junit4:junit4] 2> 14372 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10032 (-1428697453087948800)]} 0 0
[junit4:junit4] 2> 14373 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[32 (-1428697453088997376)]} 0 0
[junit4:junit4] 2> 14374 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10055 (1428697453090045952)]} 0 0
[junit4:junit4] 2> 14375 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[55 (1428697453091094528)]} 0 0
[junit4:junit4] 2> 14376 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10055 (1428697453092143104)]} 0 0
[junit4:junit4] 2> 14377 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[55 (1428697453093191680)]} 0 0
[junit4:junit4] 2> 14420 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10056 (1428697453137231872)]} 0 1
[junit4:junit4] 2> 14421 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[56 (1428697453138280448)]} 0 1
[junit4:junit4] 2> 14422 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10056 (1428697453140377600)]} 0 0
[junit4:junit4] 2> 14423 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[56 (1428697453141426176)]} 0 1
[junit4:junit4] 2> 14485 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10035 (-1428697453205389312)]} 0 1
[junit4:junit4] 2> 14485 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[35 (-1428697453206437888)]} 0 0
[junit4:junit4] 2> 14487 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[10035 (-1428697453208535040)]} 0 0
[junit4:junit4] 2> 14487 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[35 (-1428697453208535041)]} 0 0
[junit4:junit4] 2> 14489 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10057 (1428697453210632192)]} 0 0
[junit4:junit4] 2> 14489 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[57 (1428697453210632193)]} 0 0
[junit4:junit4] 2> 14492 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10057 (1428697453212729344)]} 0 1
[junit4:junit4] 2> 14492 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[57 (1428697453212729345)]} 0 1
[junit4:junit4] 2> 14495 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[36 (-1428697453216923649)]} 0 0
[junit4:junit4] 2> 14495 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10036 (-1428697453216923648)]} 0 0
[junit4:junit4] 2> 14497 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[36 (-1428697453217972224)]} 0 1
[junit4:junit4] 2> 14497 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[10036 (-1428697453219020800)]} 0 0
[junit4:junit4] 2> 14499 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[58 (1428697453220069376)]} 0 1
[junit4:junit4] 2> 14499 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10058 (1428697453221117952)]} 0 0
[junit4:junit4] 2> 14501 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[58 (1428697453223215104)]} 0 0
[junit4:junit4] 2> 14502 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10058 (1428697453223215105)]} 0 1
[junit4:junit4] 2> 14566 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[37 (-1428697453291372544)]} 0 0
[junit4:junit4] 2> 14566 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[10037 (-1428697453291372545)]} 0 0
[junit4:junit4] 2> 14568 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[37 (-1428697453293469696)]} 0 1
[junit4:junit4] 2> 14568 T2134 C103 P58959 /update {wt=javabin&version=2} {delete=[10037 (-1428697453293469697)]} 0 0
[junit4:junit4] 2> 14570 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[59 (1428697453294518272)]} 0 1
[junit4:junit4] 2> 14570 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10059 (1428697453294518273)]} 0 1
[junit4:junit4] 2> 14572 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[59 (1428697453297664000)]} 0 1
[junit4:junit4] 2> 14572 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10059 (1428697453297664001)]} 0 0
[junit4:junit4] 2> 14612 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10060 (1428697453338558465)]} 0 1
[junit4:junit4] 2> 14612 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[60 (1428697453338558464)]} 0 1
[junit4:junit4] 2> 14614 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10060 (1428697453341704192)]} 0 0
[junit4:junit4] 2> 14614 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[60 (1428697453341704193)]} 0 0
[junit4:junit4] 2> 14707 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[61 (1428697453438173185)]} 0 1
[junit4:junit4] 2> 14707 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10061 (1428697453438173184)]} 0 1
[junit4:junit4] 2> 14709 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[61 (1428697453440270336)]} 0 1
[junit4:junit4] 2> 14709 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10061 (1428697453441318912)]} 0 0
[junit4:junit4] 2> 14790 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10062 (1428697453526253569)]} 0 0
[junit4:junit4] 2> 14791 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[62 (1428697453526253568)]} 0 1
[junit4:junit4] 2> 14793 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10062 (1428697453528350720)]} 0 1
[junit4:junit4] 2> 14793 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[62 (1428697453528350721)]} 0 1
[junit4:junit4] 2> 14806 T2157 C101 P42744 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:58959/f_/f/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 14806 T2157 C101 P42744 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:42744/f_/f START replicas=[http://127.0.0.1:58959/f_/f/collection1/] nUpdates=100
[junit4:junit4] 2> 14807 T2157 C101 P42744 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 14807 T2157 C101 P42744 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 14807 T2157 C101 P42744 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 14807 T2132 C103 P58959 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 14807 T2157 C101 P42744 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 14808 T2157 C101 P42744 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4] 2> 14808 T2157 C101 P42744 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:58959/f_/f/collection1/. core=collection1
[junit4:junit4] 2> 14808 T2157 C101 P42744 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 14811 T2133 C103 P58959 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 14820 T2133 C103 P58959 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c8ff5f6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c8ffcb9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c8ff5f6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c8ffcb9),segFN=segments_2,generation=2,filenames=[_0.fnm, _0_Lucene41_0.pos, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene41_0.doc, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt, _0_dv.cfe]
[junit4:junit4] 2> 14821 T2133 C103 P58959 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0.fnm, _0_Lucene41_0.pos, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene41_0.doc, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt, _0_dv.cfe]
[junit4:junit4] 2> 14822 T2133 C103 P58959 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1
[junit4:junit4] 2> 14823 T2133 C103 P58959 oass.SolrIndexSearcher.<init> Opening Searcher@1c57a818 realtime
[junit4:junit4] 2> 14823 T2133 C103 P58959 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 14823 T2133 C103 P58959 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 12
[junit4:junit4] 2> 14824 T2157 C101 P42744 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 14824 T2157 C101 P42744 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 14825 T2131 C103 P58959 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 14825 T2131 C103 P58959 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 14825 T2157 C101 P42744 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 14825 T2157 C101 P42744 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 14826 T2157 C101 P42744 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 14827 T2132 C103 P58959 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1
[junit4:junit4] 2> 14828 T2132 C103 P58959 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty1/index
[junit4:junit4] 2> 14828 T2132 C103 P58959 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 14828 T2157 C101 P42744 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 14
[junit4:junit4] 2> 14829 T2157 C101 P42744 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index.20130305213427382 forceNew:false
[junit4:junit4] 2> 14829 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 14829 T2157 C101 P42744 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c3ebff7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c3ec567)) fullCopy=true
[junit4:junit4] 2> 14831 T2133 C103 P58959 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14833 T2134 C103 P58959 REQ /replication {file=_0_Lucene41_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14835 T2131 C103 P58959 REQ /replication {file=_0_1.del&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14837 T2132 C103 P58959 REQ /replication {file=_0_dv.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14840 T2133 C103 P58959 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14842 T2134 C103 P58959 REQ /replication {file=_0_Lucene41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14844 T2131 C103 P58959 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14846 T2132 C103 P58959 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14848 T2133 C103 P58959 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14850 T2134 C103 P58959 REQ /replication {file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14852 T2131 C103 P58959 REQ /replication {file=_0_Lucene41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14854 T2132 C103 P58959 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14856 T2133 C103 P58959 REQ /replication {file=_0_Lucene41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14858 T2134 C103 P58959 REQ /replication {file=_0_dv.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 14859 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index
[junit4:junit4] 2> 14859 T2157 C101 P42744 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 14859 T2157 C101 P42744 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130305213427382
[junit4:junit4] 2> 14860 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 14860 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 14860 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 14861 T2157 C101 P42744 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 14861 T2157 C101 P42744 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 14861 T2157 C101 P42744 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 14862 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index
[junit4:junit4] 2> 14862 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 14862 T2157 C101 P42744 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index/ new=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index.20130305213427382
[junit4:junit4] 2> 14864 T2157 C101 P42744 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c3ebff7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c3ec567)),segFN=segments_2,generation=2,filenames=[_0.fnm, _0_Lucene41_0.pos, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene41_0.doc, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4] 2> 14864 T2157 C101 P42744 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0.fnm, _0_Lucene41_0.pos, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene41_0.doc, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4] 2> 14865 T2157 C101 P42744 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 14865 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 14866 T2157 C101 P42744 oass.SolrIndexSearcher.<init> Opening Searcher@1c5f30f8 main
[junit4:junit4] 2> 14867 T2156 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c5f30f8 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C124/38)}
[junit4:junit4] 2> 14868 T2156 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index
[junit4:junit4] 2> 14868 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index.20130305213427382
[junit4:junit4] 2> 14868 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index
[junit4:junit4] 2> 14868 T2157 C101 P42744 oasc.CachingDirectoryFactory.close Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index
[junit4:junit4] 2> 14868 T2157 C101 P42744 oash.SnapPuller$2.preClose removing old index files MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c679f4b lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c67a60e)
[junit4:junit4] 2> 14869 T2157 C101 P42744 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index
[junit4:junit4] 2> 14869 T2157 C101 P42744 oash.SnapPuller$2.postClose removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c679f4b lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c67a60e)
[junit4:junit4] 2> 14869 T2157 C101 P42744 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4] 2> 14869 T2165 C101 P42744 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=7021
[junit4:junit4] 2> 14870 T2165 C101 P42744 oasu.DirectUpdateHandler2.commit start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 14871 T2165 C101 P42744 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c3ebff7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c3ec567)),segFN=segments_2,generation=2,filenames=[_0.fnm, _0_Lucene41_0.pos, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene41_0.doc, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4] 2> commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c3ebff7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c3ec567)),segFN=segments_3,generation=3,filenames=[_0.fnm, _0_Lucene41_0.pos, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene41_0.doc, _0_nrm.cfe, _0.fdx, _0.si, _0_Lucene41_0.tim, segments_3, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4] 2> 14872 T2165 C101 P42744 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0_Lucene41_0.pos, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene41_0.doc, _0_nrm.cfe, _0.fdx, _0.si, _0_Lucene41_0.tim, segments_3, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4] 2> 14873 T2165 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 14874 T2165 C101 P42744 oass.SolrIndexSearcher.<init> Opening Searcher@1c483f6e main
[junit4:junit4] 2> 14874 T2165 C101 P42744 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 14875 T2156 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c483f6e main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C124/38)}
[junit4:junit4] 2> 14875 T2156 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index.20130305213427382
[junit4:junit4] 2> 14875 T2165 C101 P42744 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=7021}
[junit4:junit4] 2> 14875 T2157 C101 P42744 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 14876 T2157 C101 P42744 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 14876 T2157 C101 P42744 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 14877 T2157 C101 P42744 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 14884 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10063 (1428697453624819712)]} 0 0
[junit4:junit4] 2> 14885 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[63 (1428697453624819713)]} 0 1
[junit4:junit4] 2> 14887 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10063 (1428697453626916864)]} 0 1
[junit4:junit4] 2> 14887 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[63 (1428697453627965440)]} 0 0
[junit4:junit4] 2> 14967 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10064 (1428697453711851520)]} 0 0
[junit4:junit4] 2> 14968 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[64 (1428697453711851521)]} 0 1
[junit4:junit4] 2> 14970 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10064 (1428697453713948672)]} 0 1
[junit4:junit4] 2> 14970 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[64 (1428697453713948673)]} 0 1
[junit4:junit4] 2> 15066 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[10039 (-1428697453815660544)]} 0 0
[junit4:junit4] 2> 15066 T2111 C102 P55620 /update {wt=javabin&version=2} {delete=[39 (-1428697453815660545)]} 0 0
[junit4:junit4] 2> 15068 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10039 (-1428697453817757696)]} 0 0
[junit4:junit4] 2> 15068 T2132 C103 P58959 /update {wt=javabin&version=2} {delete=[39 (-1428697453817757697)]} 0 0
[junit4:junit4] 2> 15070 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10065 (1428697453818806272)]} 0 1
[junit4:junit4] 2> 15070 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[65 (1428697453819854848)]} 0 0
[junit4:junit4] 2> 15072 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10065 (1428697453821952000)]} 0 0
[junit4:junit4] 2> 15072 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[65 (1428697453821952001)]} 0 0
[junit4:junit4] 2> 15158 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[10040 (-1428697453912129536)]} 0 0
[junit4:junit4] 2> 15159 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[40 (-1428697453912129537)]} 0 1
[junit4:junit4] 2> 15161 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10040 (-1428697453914226688)]} 0 1
[junit4:junit4] 2> 15161 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[40 (-1428697453915275264)]} 0 0
[junit4:junit4] 2> 15163 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10066 (1428697453917372416)]} 0 0
[junit4:junit4] 2> 15163 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[66 (1428697453917372417)]} 0 0
[junit4:junit4] 2> 15165 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10066 (1428697453919469568)]} 0 0
[junit4:junit4] 2> 15166 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[66 (1428697453919469569)]} 0 1
[junit4:junit4] 2> 15264 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[67 (1428697454022230017)]} 0 1
[junit4:junit4] 2> 15264 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10067 (1428697454022230016)]} 0 1
[junit4:junit4] 2> 15266 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[67 (1428697454025375744)]} 0 0
[junit4:junit4] 2> 15267 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10067 (1428697454025375745)]} 0 1
[junit4:junit4] 2> 15340 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10068 (1428697454102970369)]} 0 0
[junit4:junit4] 2> 15340 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[68 (1428697454102970368)]} 0 0
[junit4:junit4] 2> 15342 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10068 (1428697454105067520)]} 0 0
[junit4:junit4] 2> 15343 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[68 (1428697454105067521)]} 0 1
[junit4:junit4] 2> 15369 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[10041 (-1428697454133379072)]} 0 0
[junit4:junit4] 2> 15370 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[41 (-1428697454134427648)]} 0 0
[junit4:junit4] 2> 15372 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[10041 (-1428697454135476224)]} 0 0
[junit4:junit4] 2> 15372 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[41 (-1428697454136524800)]} 0 0
[junit4:junit4] 2> 15374 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10069 (1428697454137573376)]} 0 1
[junit4:junit4] 2> 15374 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[69 (1428697454137573377)]} 0 1
[junit4:junit4] 2> 15376 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10069 (1428697454139670528)]} 0 1
[junit4:junit4] 2> 15376 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[69 (1428697454140719104)]} 0 0
[junit4:junit4] 2> 15417 T2113 C102 P55620 /update {wt=javabin&version=2} {delete=[10044 (-1428697454182662144)]} 0 1
[junit4:junit4] 2> 15417 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[44 (-1428697454183710720)]} 0 0
[junit4:junit4] 2> 15418 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[10044 (-1428697454184759296)]} 0 0
[junit4:junit4] 2> 15419 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[44 (-1428697454185807872)]} 0 0
[junit4:junit4] 2> 15420 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10070 (1428697454186856448)]} 0 0
[junit4:junit4] 2> 15421 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[70 (1428697454187905024)]} 0 0
[junit4:junit4] 2> 15422 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10070 (1428697454188953600)]} 0 0
[junit4:junit4] 2> 15423 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[70 (1428697454190002176)]} 0 0
[junit4:junit4] 2> 15521 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10071 (1428697454291714048)]} 0 1
[junit4:junit4] 2> 15522 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[71 (1428697454292762624)]} 0 1
[junit4:junit4] 2> 15523 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[10071 (1428697454294859776)]} 0 0
[junit4:junit4] 2> 15524 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[71 (1428697454295908352)]} 0 0
[junit4:junit4] 2> 15544 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15545 T2119 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42744_f_%2Ff",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42744/f_/f"}
[junit4:junit4] 2> 15547 T2118 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> 15547 T2138 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> 15547 T2154 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> 15547 T2125 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> 15591 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[10072 (1428697454366162944)]} 0 0
[junit4:junit4] 2> 15592 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[72 (1428697454367211520)]} 0 0
[junit4:junit4] 2> C101_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:42744_f_%2Ff, base_url=http://127.0.0.1:42744/f_/f}
[junit4:junit4] 2> 15596 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10072 (1428697454368260096)]} 0 1
[junit4:junit4] 2> 15596 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10072 (1428697454368260096)]} 0 3
[junit4:junit4] 2> 15597 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[72 (1428697454369308672)]} 0 1
[junit4:junit4] 2> 15597 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[72 (1428697454369308672)]} 0 3
[junit4:junit4] 2> 15649 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[10046 (-1428697454426980352)]} 0 0
[junit4:junit4] 2> 15650 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[46 (-1428697454428028928)]} 0 0
[junit4:junit4] 2> 15653 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10046 (-1428697454429077504)]} 0 0
[junit4:junit4] 2> 15654 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10046 (-1428697454429077504)]} 0 3
[junit4:junit4] 2> 15654 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[46 (-1428697454430126080)]} 0 1
[junit4:junit4] 2> 15654 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[46 (-1428697454430126080)]} 0 2
[junit4:junit4] 2> 15656 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[10073 (1428697454433271808)]} 0 1
[junit4:junit4] 2> 15656 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[73 (1428697454434320384)]} 0 0
[junit4:junit4] 2> 15660 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10073 (1428697454435368960)]} 0 1
[junit4:junit4] 2> 15660 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[10073 (1428697454435368960)]} 0 3
[junit4:junit4] 2> 15660 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[73 (1428697454436417536)]} 0 0
[junit4:junit4] 2> 15661 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[73 (1428697454436417536)]} 0 3
[junit4:junit4] 2> 15716 T2112 C102 P55620 /update {wt=javabin&version=2} {delete=[10047 (-1428697454497234944)]} 0 0
[junit4:junit4] 2> 15717 T2114 C102 P55620 /update {wt=javabin&version=2} {delete=[47 (-1428697454498283520)]} 0 0
[junit4:junit4] 2> 15720 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10047 (-1428697454499332096)]} 0 0
[junit4:junit4] 2> 15720 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[47 (-1428697454499332097)]} 0 0
[junit4:junit4] 2> 15720 T2131 C103 P58959 /update {wt=javabin&version=2} {delete=[10047 (-1428697454499332096)]} 0 2
[junit4:junit4] 2> 15721 T2133 C103 P58959 /update {wt=javabin&version=2} {delete=[47 (-1428697454499332097)]} 0 3
[junit4:junit4] 2> 15723 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10074 (1428697454503526400)]} 0 1
[junit4:junit4] 2> 15723 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[74 (1428697454503526401)]} 0 1
[junit4:junit4] 2> 15726 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10074 (1428697454505623552)]} 0 0
[junit4:junit4] 2> 15727 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[74 (1428697454506672128)]} 0 1
[junit4:junit4] 2> 15727 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10074 (1428697454505623552)]} 0 3
[junit4:junit4] 2> 15727 T2132 C103 P58959 /update {wt=javabin&version=2} {add=[74 (1428697454506672128)]} 0 3
[junit4:junit4] 2> 15777 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10075 (1428697454561198080)]} 0 0
[junit4:junit4] 2> 15777 T2114 C102 P55620 /update {wt=javabin&version=2} {add=[75 (1428697454561198081)]} 0 0
[junit4:junit4] 2> 15784 T2149 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10075 (1428697454564343808)]} 0 1
[junit4:junit4] 2> 15785 T2147 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[75 (1428697454564343809)]} 0 2
[junit4:junit4] 2> 15785 T2131 C103 P58959 /update {wt=javabin&version=2} {add=[10075 (1428697454564343808)]} 0 5
[junit4:junit4] 2> 15786 T2133 C103 P58959 /update {wt=javabin&version=2} {add=[75 (1428697454564343809)]} 0 6
[junit4:junit4] 2> 15810 T2096 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 15810 T2096 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15812 T2111 C102 P55620 /update {wt=javabin&version=2} {add=[10076 (1428697454596849664)]} 0 1
[junit4:junit4] 2> 15812 T2113 C102 P55620 /update {wt=javabin&version=2} {add=[76 (1428697454596849665)]} 0 1
[junit4:junit4] 2> 15813 T2096 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1c5caaba
[junit4:junit4] 2> 15815 T2148 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10076 (1428697454598946816)]} 0 0
[junit4:junit4] 2> 15816 T2150 C101 P42744 /update {distrib.from=http://127.0.0.1:58959/f_/f/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[76 (1428697454598946817)]} 0 1
[junit4:junit4] 2> 15816 T2134 C103 P58959 /update {wt=javabin&version=2} {add=[10076 (1428697454598946816)]} 0 3
[junit4:junit4] 2> 15816 T2150 C101 P42744 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1c5caaba
[junit4:junit4] 2> 15817 T2150 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index.20130305213427382
[junit4:junit4] 2> 15817 T2096 oasc.SolrException.log SEVERE org.apache.solr.common.SolrException: Failed to unregister info bean: /update
[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:959)
[junit4:junit4] 2> at org.apache.solr.core.CoreMaps.clearMaps(CoreContainer.java:1448)
[junit4:junit4] 2> at org.apache.solr.core.CoreContainer.shutdown(CoreContainer.java:695)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.destroy(SolrDispatchFilter.java:136)
[junit4:junit4] 2> at org.apache.solr.cloud.ChaosMonkey.stopJettySolrRunner(ChaosMonkey.java:202)
[junit4:junit4] 2> at org.apache.solr.cloud.ChaosMonkey.stop(ChaosMonkey.java:510)
[junit4:junit4] 2> at org.apache.solr.cloud.ChaosMonkey.stopJetty(ChaosMonkey.java:181)
[junit4:junit4] 2> at org.apache.solr.cloud.ChaosMonkey.stopShard(ChaosMonkey.java:175)
[junit4:junit4] 2> at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:69)
[junit4:junit4] 2> at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit4:junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4:junit4] 2> at java.lang.reflect.Method.invoke(Method.java:597)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:738)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:774)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:683)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:44)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:56)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2> Caused by: javax.management.InstanceNotFoundException: solr/collection1:type=/update,id=org.apache.solr.handler.UpdateRequestHandler
[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> ... 51 more
[junit4:junit4] 2>
[junit4:junit4] 2> 15818 T2150 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 15820 T2096 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=10,adds=10,deletesById=4,deletesByQuery=0,errors=0,cumulative_adds=74,cumulative_deletesById=24,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 15821 T2150 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2/index.20130305213427382
[junit4:junit4] 2> 15821 T2096 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 15821 T2150 C101 P42744 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-1362512052582/jetty2
[junit4:junit4] 2> 15821 T2096 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 15822 T2096 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 15824 T2150 C101 P42744 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=10,deletesById=4,deletesByQuery=0,errors=0,cumulative_adds=74,cumulative_deletesById=24,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 15851 T2096 C101 P42744 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c3ebff7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c3ec567)),segFN=segments_3,generation=3,filenames=[_0.fnm, _0_Lucene41_0.pos, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene41_0.doc, _0_nrm.cfe, _0.fdx, _0.si, _0_Lucene41_0.tim, segments_3, _0.fdt, _0_Lucene41_0.tip, _0_dv.cfe]
[junit4:junit4] 2> commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c3ebff7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c3ec567)),segFN=segments_4,generation=4,filenames=[_1_Lucene41_0.doc, _0_Lucene41_0.pos, _0_dv.cfs, _1.fnm, _1_dv.cfs, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _1_nrm.cfs, _0.fnm, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _0_nrm.cfs, _1_dv.cfe, _1_nrm.cfe, _1_Lucene41_0.pos, _1.fdx, _0_Lucene41_0.doc, _1.fdt, _1.si, _0_nrm.cfe, _0.fdx, _0_2.del, _0.fdt, segments_4, _0_dv.cfe]
[junit4:junit4] 2> 15851 T2112 C102 P55620 /update {wt=javabin&version=2} {add=[10077 (1428697454638792704)]} 0 0
[junit4:junit4] 2> 15852 T2096 C101 P42744 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_1_Lucene41_0.doc, _0_Lucene41_0.pos, _0_dv.cfs, _1.fnm, _1_dv.cfs, _0
[...truncated too long message...]
erImpl.run SessionTrackerImpl exited loop!
[junit4:junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=th, timezone=Europe/Tallinn
[junit4:junit4] 2> NOTE: Linux 3.2.0-38-generic amd64/Oracle Corporation 1.6.0_33 (64-bit)/cpus=8,threads=1,free=85942088,total=415571968
[junit4:junit4] 2> NOTE: All tests run in this JVM: [PrimUtilsTest, OverseerCollectionProcessorTest, TestSolrCoreProperties, TestBadConfig, FileBasedSpellCheckerTest, CacheHeaderTest, SchemaVersionSpecificBehaviorTest, TestTrie, TestConfig, TestExtendedDismaxParser, TestJoin, TestIBSimilarityFactory, UnloadDistributedZkTest, ResponseLogComponentTest, MoreLikeThisHandlerTest, SimpleFacetsTest, WordBreakSolrSpellCheckerTest, CSVRequestHandlerTest, TestPHPSerializedResponseWriter, FastVectorHighlighterTest, RAMDirectoryFactoryTest, TestSolrDeletionPolicy2, OverseerTest, TestPerFieldSimilarity, TestLMDirichletSimilarityFactory, SearchHandlerTest, TestXIncludeConfig, PolyFieldTest, PrimitiveFieldTypeTest, TestQueryUtils, AlternateDirectoryTest, AutoCommitTest, TestSolrDeletionPolicy1, QueryEqualityTest, BadComponentTest, AnalysisAfterCoreReloadTest, ChaosMonkeyNothingIsSafeTest, TestStressVersions, TestReplicationHandler, LukeRequestHandlerTest, LoggingHandlerTest, LegacyHTMLStripCharFilterTest, ZkControllerTest, ReturnFieldsTest, SuggesterFSTTest, CoreAdminHandlerTest, TestReversedWildcardFilterFactory, TestCharFilters, QueryParsingTest, DirectSolrConnectionTest, MinimalSchemaTest, ResourceLoaderTest, SuggesterTest, TestSolrQueryParser, StatelessScriptUpdateProcessorFactoryTest, SynonymTokenizerTest, BinaryUpdateRequestHandlerTest, ShardRoutingTest, SyncSliceTest, TestStressRecovery, RecoveryZkTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RecoveryZkTest -Dtests.seed=E7A995A754760E8E -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=th -Dtests.timezone=Europe/Tallinn -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 0.00s J0 | RecoveryZkTest (suite) <<<
[junit4:junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=2155, name=coreLoadExecutor-1015-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:33)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:267)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:223)
[junit4:junit4] > at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:244)
[junit4:junit4] > at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:458)
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:733)
[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(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c5d7b1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c5d821b))
[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=2157, 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:33)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:267)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:223)
[junit4:junit4] > at org.apache.solr.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(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1c3ebff7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c3ec567))
[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 34.69s, 1 test, 2 errors <<< FAILURES!
[...truncated 416 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:361: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1213: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:877: There were test failures: 261 suites, 1105 tests, 2 suite-level errors, 13 ignored (7 assumptions)
Total time: 77 minutes 55 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jrockit-jdk1.6.0_33-R28.2.4-4.1.0 -XnoOpt
Email was triggered for: Failure
Sending email for trigger: Failure
RE: [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b79) - Build # 4583 - Failure!
Posted by Uwe Schindler <uw...@thetaphi.de>.
Hi,
I got a little bit further when trying to debug this. I was able to hook on the hanging JVM with GDB and get a stack trace (see attachment). There are several threads, where the G1 garbage collector is in the native stack traces that all hang waiting in the pthread_cond_wait () syscall. So it seems to be some deadlock in the G1-Collector.
I will report this to the hotspot mailing list. This only happens with G1 garbage collector and was only seen with 32 bit JVM until now (and only happens in the UIMA test suite, but not in a specific test).
Uwe
-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de
> -----Original Message-----
> From: Policeman Jenkins Server [mailto:jenkins@thetaphi.de]
> Sent: Tuesday, March 05, 2013 6:35 PM
> To: dev@lucene.apache.org
> Subject: [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b79) - Build #
> 4583 - Failure!
>
> Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4583/
> Java: 32bit/jdk1.8.0-ea-b79 -server -XX:+UseG1GC
>
> All tests passed
>
> Build Log:
> [...truncated 5905 lines...]
> [junit4:junit4] ERROR: JVM J0 ended with an exception, command line:
> /var/lib/jenkins/tools/java/32bit/jdk1.8.0-ea-b79/jre/bin/java -server -
> XX:+UseG1GC -XX:+HeapDumpOnOutOfMemoryError -
> XX:HeapDumpPath=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/heapdumps -Dtests.prefix=tests -Dtests.seed=FE2388371D24A1F6 -
> Xmx512M -Dtests.iters= -Dtests.verbose=false -Dtests.infostream=false -
> Dtests.codec=random -Dtests.postingsformat=random -
> Dtests.docvaluesformat=random -Dtests.locale=random -
> Dtests.timezone=random -Dtests.directory=random -
> Dtests.linedocsfile=europarl.lines.txt.gz -Dtests.luceneMatchVersion=5.0 -
> Dtests.cleanthreads=perMethod -
> Djava.util.logging.config.file=/mnt/ssd/jenkins/workspace/Lucene-Solr-
> trunk-Linux/lucene/tools/junit4/logging.properties -Dtests.nightly=false -
> Dtests.weekly=false -Dtests.slow=true -Dtests.asserts.gracious=false -
> Dtests.multiplier=3 -DtempDir=. -Djava.io.tmpdir=. -
> Djunit4.tempDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/build/analysis/uima/test/temp -
> Dclover.db.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/build/clover/db -
> Djava.security.manager=org.apache.lucene.util.TestSecurityManager -
> Djava.security.policy=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/tools/junit4/tests.policy -Dlucene.version=5.0-SNAPSHOT -
> Djetty.testMode=1 -Djetty.insecurerandom=1 -
> Dsolr.directoryFactory=org.apache.solr.core.MockDirectoryFactory -
> Djava.awt.headless=true -Dfile.encoding=ISO-8859-1 -classpath
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/build/analysis/uima/classes/test:/mnt/ssd/jenkins/workspace
> /Lucene-Solr-trunk-Linux/lucene/build/test-
> framework/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/build/codecs/classes/java:/mnt/ssd/jenkins/workspace/Lucen
> e-Solr-trunk-Linux/lucene/build/analysis/common/lucene-analyzers-
> common-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-
> trunk-Linux/lucene/analysis/uima/src/test-
> files:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/analysis/uima/lib/Tagger-
> 2.3.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/analysis/uima/lib/WhitespaceTokenizer-
> 2.3.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/analysis/uima/lib/uimaj-core-
> 2.3.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/build/core/classes/java:/mnt/ssd/jenkins/workspace/Lucene-
> Solr-trunk-Linux/lucene/test-framework/lib/junit-
> 4.10.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/test-
> framework/lib/randomizedtesting-runner-
> 2.0.8.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/build/analysis/uima/classes/java:/var/lib/jenkins/tools/hudson
> .tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-
> launcher.jar:/var/lib/jenkins/.ant/lib/ivy-
> 2.3.0.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/
> lib/ant-
> jai.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib
> /ant-
> swing.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
> /lib/ant-apache-
> oro.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/li
> b/ant-
> jmf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/li
> b/ant-apache-
> xalan2.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.
> 2/lib/ant-
> javamail.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.
> 8.2/lib/ant-apache-
> resolver.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.
> 8.2/lib/ant-
> testutil.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.
> 2/lib/ant-commons-
> logging.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.
> 2/lib/ant-apache-
> log4j.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/
> lib/ant-
> junit.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/
> lib/ant-
> jsch.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/li
> b/ant-commons-
> net.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/li
> b/ant-apache-
> bsf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/li
> b/ant-
> jdepend.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.
> 8.2/lib/ant-
> netrexx.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.
> 8.2/lib/ant-apache-
> regexp.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.
> 2/lib/ant-
> junit4.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
> /lib/ant.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8
> .2/lib/ant-apache-
> bcel.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/l
> ib/ant-antlr.jar:/var/lib/jenkins/tools/java/32bit/jdk1.8.0-ea-
> b79/lib/tools.jar:/var/lib/jenkins/.ivy2/cache/com.carrotsearch.randomizedt
> esting/junit4-ant/jars/junit4-ant-2.0.8.jar -ea:org.apache.lucene... -
> ea:org.apache.solr... com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -
> flush -eventsfile /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/build/analysis/uima/test/temp/junit4-J0-
> 20130305_170710_622.events @/mnt/ssd/jenkins/workspace/Lucene-Solr-
> trunk-Linux/lucene/build/analysis/uima/test/temp/junit4-J0-
> 20130305_170710_622.suites
> [junit4:junit4] ERROR: JVM J0 ended with an exception: Forked process
> returned with error code: 137.
> [junit4:junit4] at
> com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1253)
> [junit4:junit4] at
> com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:66)
> [junit4:junit4] at
> com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:821)
> [junit4:junit4] at
> com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:818)
> [junit4:junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> [junit4:junit4] at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.jav
> a:1110)
> [junit4:junit4] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> va:603)
> [junit4:junit4] at java.lang.Thread.run(Thread.java:722)
>
> BUILD FAILED
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:381: The
> following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:361: The
> following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The
> following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build.xml:548:
> The following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-
> build.xml:1758: The following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/analysis/build.xml:105: The following error occurred while
> executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-
> Linux/lucene/analysis/build.xml:38: The following error occurred while
> executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/module-
> build.xml:61: The following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-
> build.xml:1213: The following error occurred while executing this line:
> /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-
> build.xml:877: At least one slave process threw an exception, first: Forked
> process returned with error code: 137.
>
> Total time: 43 minutes 3 seconds
> Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording
> test results Description set: Java: 32bit/jdk1.8.0-ea-b79 -server -
> XX:+UseG1GC Email was triggered for: Failure Sending email for trigger:
> Failure
>