You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/09/12 14:16:41 UTC
[JENKINS] Lucene-Solr-NightlyTests-master - Build # 1640 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/1640/
2 tests failed.
FAILED: org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates
Error Message:
Java heap space
Stack Trace:
java.lang.OutOfMemoryError: Java heap space
at org.apache.lucene.store.RAMFile.newBuffer(RAMFile.java:84)
at org.apache.lucene.store.RAMFile.addBuffer(RAMFile.java:57)
at org.apache.lucene.store.RAMOutputStream.switchCurrentBuffer(RAMOutputStream.java:168)
at org.apache.lucene.store.RAMOutputStream.writeBytes(RAMOutputStream.java:154)
at org.apache.lucene.store.MockIndexOutputWrapper.writeBytes(MockIndexOutputWrapper.java:141)
at org.apache.lucene.codecs.lucene70.Lucene70DocValuesConsumer.addBinaryField(Lucene70DocValuesConsumer.java:348)
at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addBinaryField(PerFieldDocValuesFormat.java:114)
at org.apache.lucene.index.ReadersAndUpdates.handleDVUpdates(ReadersAndUpdates.java:330)
at org.apache.lucene.index.ReadersAndUpdates.writeFieldUpdates(ReadersAndUpdates.java:570)
at org.apache.lucene.index.IndexWriter.writeSomeDocValuesUpdates(IndexWriter.java:626)
at org.apache.lucene.index.FrozenBufferedUpdates.apply(FrozenBufferedUpdates.java:299)
at org.apache.lucene.index.IndexWriter.lambda$publishFrozenUpdates$3(IndexWriter.java:2600)
at org.apache.lucene.index.IndexWriter$$Lambda$110/1815498900.process(Unknown Source)
at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5097)
at org.apache.lucene.index.IndexWriter.updateDocValues(IndexWriter.java:1783)
at org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates(TestBinaryDocValuesUpdates.java:1324)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1742)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
FAILED: org.apache.solr.cloud.MoveReplicaHDFSTest.testFailedMove
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:41156/solr/MoveReplicaHDFSTest_failed_coll_true, http://127.0.0.1:46777/solr/MoveReplicaHDFSTest_failed_coll_true]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:41156/solr/MoveReplicaHDFSTest_failed_coll_true, http://127.0.0.1:46777/solr/MoveReplicaHDFSTest_failed_coll_true]
at __randomizedtesting.SeedInfo.seed([A78659BA58953D1C:D4B8A48EF46E8CC]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:462)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1107)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:994)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942)
at org.apache.solr.cloud.MoveReplicaTest.testFailedMove(MoveReplicaTest.java:291)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1742)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:944)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:830)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:891)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:41156/solr/MoveReplicaHDFSTest_failed_coll_true: no servers hosting shard: shard2
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:436)
... 46 more
Build Log:
[...truncated 1369 lines...]
[junit4] Suite: org.apache.lucene.index.TestBinaryDocValuesUpdates
[junit4] 1> TEST: isNRT=false reader1=StandardDirectoryReader(segments_1:4 _0(8.0.0):C2)
[junit4] 1> TEST: now reopen
[junit4] 2> sep 12, 2018 3:46:43 AM com.carrotsearch.randomizedtesting.RandomizedRunner$QueueUncaughtExceptionsHandler uncaughtException
[junit4] 2> ADVERTENCIA: Uncaught exception in thread: Thread[Lucene Merge Thread #1,5,TGRP-TestBinaryDocValuesUpdates]
[junit4] 2> org.apache.lucene.index.MergePolicy$MergeException: org.apache.lucene.store.AlreadyClosedException: refusing to delete any files: this IndexWriter hit an unrecoverable exception
[junit4] 2> at __randomizedtesting.SeedInfo.seed([946FDCB4526E941E]:0)
[junit4] 2> at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:704)
[junit4] 2> at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:684)
[junit4] 2> Caused by: org.apache.lucene.store.AlreadyClosedException: refusing to delete any files: this IndexWriter hit an unrecoverable exception
[junit4] 2> at org.apache.lucene.index.IndexFileDeleter.ensureOpen(IndexFileDeleter.java:349)
[junit4] 2> at org.apache.lucene.index.IndexFileDeleter.deleteFiles(IndexFileDeleter.java:669)
[junit4] 2> at org.apache.lucene.index.IndexFileDeleter.deleteNewFiles(IndexFileDeleter.java:664)
[junit4] 2> at org.apache.lucene.index.IndexWriter.deleteNewFiles(IndexWriter.java:5015)
[junit4] 2> at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4530)
[junit4] 2> at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4066)
[junit4] 2> at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
[junit4] 2> at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
[junit4] 2> Caused by: java.lang.OutOfMemoryError: Java heap space
[junit4] 2> at org.apache.lucene.store.RAMFile.newBuffer(RAMFile.java:84)
[junit4] 2> at org.apache.lucene.store.RAMFile.addBuffer(RAMFile.java:57)
[junit4] 2> at org.apache.lucene.store.RAMOutputStream.switchCurrentBuffer(RAMOutputStream.java:168)
[junit4] 2> at org.apache.lucene.store.RAMOutputStream.writeBytes(RAMOutputStream.java:154)
[junit4] 2> at org.apache.lucene.store.MockIndexOutputWrapper.writeBytes(MockIndexOutputWrapper.java:141)
[junit4] 2> at org.apache.lucene.codecs.lucene70.Lucene70DocValuesConsumer.addBinaryField(Lucene70DocValuesConsumer.java:348)
[junit4] 2> at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addBinaryField(PerFieldDocValuesFormat.java:114)
[junit4] 2> at org.apache.lucene.index.ReadersAndUpdates.handleDVUpdates(ReadersAndUpdates.java:330)
[junit4] 2> at org.apache.lucene.index.ReadersAndUpdates.writeFieldUpdates(ReadersAndUpdates.java:570)
[junit4] 2> at org.apache.lucene.index.IndexWriter.writeSomeDocValuesUpdates(IndexWriter.java:626)
[junit4] 2> at org.apache.lucene.index.FrozenBufferedUpdates.apply(FrozenBufferedUpdates.java:299)
[junit4] 2> at org.apache.lucene.index.IndexWriter.lambda$publishFrozenUpdates$3(IndexWriter.java:2600)
[junit4] 2> at org.apache.lucene.index.IndexWriter$$Lambda$110/1815498900.process(Unknown Source)
[junit4] 2> at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5097)
[junit4] 2> at org.apache.lucene.index.IndexWriter.updateDocValues(IndexWriter.java:1783)
[junit4] 2> at org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates(TestBinaryDocValuesUpdates.java:1324)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1742)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
[junit4] 2>
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestBinaryDocValuesUpdates -Dtests.method=testTonsOfUpdates -Dtests.seed=946FDCB4526E941E -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/test-data/enwiki.random.lines.txt -Dtests.locale=es-MX -Dtests.timezone=MST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 19.4s J0 | TestBinaryDocValuesUpdates.testTonsOfUpdates <<<
[junit4] > Throwable #1: java.lang.OutOfMemoryError: Java heap space
[junit4] > at org.apache.lucene.store.RAMFile.newBuffer(RAMFile.java:84)
[junit4] > at org.apache.lucene.store.RAMFile.addBuffer(RAMFile.java:57)
[junit4] > at org.apache.lucene.store.RAMOutputStream.switchCurrentBuffer(RAMOutputStream.java:168)
[junit4] > at org.apache.lucene.store.RAMOutputStream.writeBytes(RAMOutputStream.java:154)
[junit4] > at org.apache.lucene.store.MockIndexOutputWrapper.writeBytes(MockIndexOutputWrapper.java:141)
[junit4] > at org.apache.lucene.codecs.lucene70.Lucene70DocValuesConsumer.addBinaryField(Lucene70DocValuesConsumer.java:348)
[junit4] > at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addBinaryField(PerFieldDocValuesFormat.java:114)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.handleDVUpdates(ReadersAndUpdates.java:330)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.writeFieldUpdates(ReadersAndUpdates.java:570)
[junit4] > at org.apache.lucene.index.IndexWriter.writeSomeDocValuesUpdates(IndexWriter.java:626)
[junit4] > at org.apache.lucene.index.FrozenBufferedUpdates.apply(FrozenBufferedUpdates.java:299)
[junit4] > at org.apache.lucene.index.IndexWriter.lambda$publishFrozenUpdates$3(IndexWriter.java:2600)
[junit4] > at org.apache.lucene.index.IndexWriter$$Lambda$110/1815498900.process(Unknown Source)
[junit4] > at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5097)
[junit4] > at org.apache.lucene.index.IndexWriter.updateDocValues(IndexWriter.java:1783)
[junit4] > at org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates(TestBinaryDocValuesUpdates.java:1324)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3595, name=Lucene Merge Thread #1, state=RUNNABLE, group=TGRP-TestBinaryDocValuesUpdates]
[junit4] > Caused by: org.apache.lucene.index.MergePolicy$MergeException: org.apache.lucene.store.AlreadyClosedException: refusing to delete any files: this IndexWriter hit an unrecoverable exception
[junit4] > at __randomizedtesting.SeedInfo.seed([946FDCB4526E941E]:0)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:704)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:684)
[junit4] > Caused by: org.apache.lucene.store.AlreadyClosedException: refusing to delete any files: this IndexWriter hit an unrecoverable exception
[junit4] > at org.apache.lucene.index.IndexFileDeleter.ensureOpen(IndexFileDeleter.java:349)
[junit4] > at org.apache.lucene.index.IndexFileDeleter.deleteFiles(IndexFileDeleter.java:669)
[junit4] > at org.apache.lucene.index.IndexFileDeleter.deleteNewFiles(IndexFileDeleter.java:664)
[junit4] > at org.apache.lucene.index.IndexWriter.deleteNewFiles(IndexWriter.java:5015)
[junit4] > at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4530)
[junit4] > at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4066)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
[junit4] > Caused by: java.lang.OutOfMemoryError: Java heap space
[junit4] > at org.apache.lucene.store.RAMFile.newBuffer(RAMFile.java:84)
[junit4] > at org.apache.lucene.store.RAMFile.addBuffer(RAMFile.java:57)
[junit4] > at org.apache.lucene.store.RAMOutputStream.switchCurrentBuffer(RAMOutputStream.java:168)
[junit4] > at org.apache.lucene.store.RAMOutputStream.writeBytes(RAMOutputStream.java:154)
[junit4] > at org.apache.lucene.store.MockIndexOutputWrapper.writeBytes(MockIndexOutputWrapper.java:141)
[junit4] > at org.apache.lucene.codecs.lucene70.Lucene70DocValuesConsumer.addBinaryField(Lucene70DocValuesConsumer.java:348)
[junit4] > at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addBinaryField(PerFieldDocValuesFormat.java:114)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.handleDVUpdates(ReadersAndUpdates.java:330)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.writeFieldUpdates(ReadersAndUpdates.java:570)
[junit4] > at org.apache.lucene.index.IndexWriter.writeSomeDocValuesUpdates(IndexWriter.java:626)
[junit4] > at org.apache.lucene.index.FrozenBufferedUpdates.apply(FrozenBufferedUpdates.java:299)
[junit4] > at org.apache.lucene.index.IndexWriter.lambda$publishFrozenUpdates$3(IndexWriter.java:2600)
[junit4] > at org.apache.lucene.index.IndexWriter$$Lambda$110/1815498900.process(Unknown Source)
[junit4] > at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5097)
[junit4] > at org.apache.lucene.index.IndexWriter.updateDocValues(IndexWriter.java:1783)
[junit4] > at org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates(TestBinaryDocValuesUpdates.java:1324)
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/build/core/test/J0/temp/lucene.index.TestBinaryDocValuesUpdates_946FDCB4526E941E-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene80): {bdv=PostingsFormat(name=MockRandom), k1=PostingsFormat(name=Asserting), f=PostingsFormat(name=Asserting), k2=PostingsFormat(name=LuceneVarGapFixedInterval), foo=PostingsFormat(name=Asserting), dvUpdateKey=PostingsFormat(name=MockRandom), upd=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), updKey=PostingsFormat(name=Asserting), id=PostingsFormat(name=LuceneVarGapFixedInterval), key=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{ndv=DocValuesFormat(name=Asserting), f10=DocValuesFormat(name=Lucene70), f12=DocValuesFormat(name=Direct), f11=DocValuesFormat(name=Lucene70), f14=DocValuesFormat(name=Lucene70), f13=DocValuesFormat(name=Asserting), f0=DocValuesFormat(name=Lucene70), f16=DocValuesFormat(name=Direct), f1=DocValuesFormat(name=Direct), f15=DocValuesFormat(name=Lucene70), f2=DocValuesFormat(name=Asserting), f18=DocValuesFormat(name=Lucene70), f3=DocValuesFormat(name=Lucene70), f17=DocValuesFormat(name=Asserting), f4=DocValuesFormat(name=Lucene70), f19=DocValuesFormat(name=Lucene70), f5=DocValuesFormat(name=Direct), bdv2=DocValuesFormat(name=Lucene70), f6=DocValuesFormat(name=Asserting), f7=DocValuesFormat(name=Lucene70), number=DocValuesFormat(name=Direct), f8=DocValuesFormat(name=Lucene70), bdv1=DocValuesFormat(name=Lucene70), f9=DocValuesFormat(name=Direct), id=DocValuesFormat(name=Direct), val=DocValuesFormat(name=Lucene70), f21=DocValuesFormat(name=Lucene70), f20=DocValuesFormat(name=Asserting), f23=DocValuesFormat(name=Direct), f22=DocValuesFormat(name=Lucene70), f25=DocValuesFormat(name=Lucene70), upd=DocValuesFormat(name=Lucene70), f24=DocValuesFormat(name=Asserting), f27=DocValuesFormat(name=Direct), f26=DocValuesFormat(name=Lucene70), sort=DocValuesFormat(name=Lucene70), cf0=DocValuesFormat(name=Lucene70), f29=DocValuesFormat(name=Lucene70), f28=DocValuesFormat(name=Asserting), cf2=DocValuesFormat(name=Direct), cf1=DocValuesFormat(name=Lucene70), cf4=DocValuesFormat(name=Lucene70), cf3=DocValuesFormat(name=Asserting), cf6=DocValuesFormat(name=Direct), cf5=DocValuesFormat(name=Lucene70), cf8=DocValuesFormat(name=Lucene70), cf7=DocValuesFormat(name=Asserting), cf9=DocValuesFormat(name=Lucene70), ssdv=DocValuesFormat(name=Lucene70), sdv=DocValuesFormat(name=Lucene70), cf29=DocValuesFormat(name=Lucene70), cf27=DocValuesFormat(name=Asserting), cf28=DocValuesFormat(name=Lucene70), cf25=DocValuesFormat(name=Lucene70), cf26=DocValuesFormat(name=Direct), cf23=DocValuesFormat(name=Asserting), cf24=DocValuesFormat(name=Lucene70), cf21=DocValuesFormat(name=Lucene70), cf22=DocValuesFormat(name=Direct), cf20=DocValuesFormat(name=Lucene70), key=DocValuesFormat(name=Direct), cf=DocValuesFormat(name=Direct), cf18=DocValuesFormat(name=Lucene70), cf19=DocValuesFormat(name=Direct), f=DocValuesFormat(name=Lucene70), cf16=DocValuesFormat(name=Asserting), cf17=DocValuesFormat(name=Lucene70), cf14=DocValuesFormat(name=Lucene70), cf15=DocValuesFormat(name=Direct), cf12=DocValuesFormat(name=Asserting), control=DocValuesFormat(name=Lucene70), cf13=DocValuesFormat(name=Lucene70), cf10=DocValuesFormat(name=Lucene70), cf11=DocValuesFormat(name=Direct), bdv=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=1444, maxMBSortInHeap=6.796784115105444, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@30cec53a), locale=es-MX, timezone=MST
[junit4] 2> NOTE: Linux 4.4.0-130-generic amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=4,threads=1,free=87571128,total=477626368
[junit4] 2> NOTE: All tests run in this JVM: [TestLatLonPointDistanceSort, TestExitableDirectoryReader, TestSpanOrQuery, TestOfflineSorter, TestPayloadsOnVectors, TestNamedSPILoader, TestUnicodeUtil, TestGraphTokenizers, TestIndexedDISI, TestTransactions, TestSparseFixedBitDocIdSet, TestFloatRangeFieldQueries, TestIndexWriterOnJRECrash, TestBinaryTerms, TestIOUtils, TestIndexWriterDelete, TestIndexWriterMerging, TestBytesRefAttImpl, TestShardSearching, TestWeakIdentityMap, TestDateSort, TestPrefixQuery, TestSearchWithThreads, TestAutomaton, MultiCollectorTest, TestQueryBuilder, TestLazyProxSkipping, TestSpans, Test2BNumericDocValues, TestAxiomaticSimilarity, TestCompetitiveFreqNormAccumulator, TestUTF32ToUTF8, TestRollback, TestCodecHoldsOpenFiles, TestLongRangeFieldQueries, TestSegmentInfos, TestStringMSBRadixSorter, TestDoubleValuesSource, TestLucene50LiveDocsFormat, TestMultiThreadTermVectors, TestSortedSetDocValues, TestMultiMMap, TestBytesRef, TestRollingBuffer, TestCharsRef, TestSpanExplanations, TestNoDeletionPolicy, TestMultiTermsEnum, TestIndexSearcher, TestTermStates, TestBytesStore, TestNeedsScores, TestSumDocFreq, TestIndexWriterLockRelease, TestHugeRamFile, TestCollectionUtil, TestFilterDirectoryReader, TestDemoParallelLeafReader, TestLucene70SegmentInfoFormat, TestReaderClosed, TestLatLonDocValuesQueries, Test2BSortedDocValuesOrds, TestIndexWriterExceptions2, TestFieldMaskingSpanQuery, TestAutomatonQuery, Test2BPostings, TestManyFields, TestGeoEncodingUtils, TestIndexInput, TestOmitPositions, TestReqExclBulkScorer, TestAddIndexes, TestParallelReaderEmptyIndex, TestInfoStream, TestTermsEnum, TestIndependenceStandardized, TestComplexExplanationsOfNonMatches, TestHighCompressionMode, TestBooleanSimilarity, TestAllFilesHaveChecksumFooter, TestSimpleSearchEquivalence, TestDocValuesIndexing, TestSetOnce, TestSnapshotDeletionPolicy, TestDocument, TestBinaryDocument, TestDateTools, TestField, TestIntRange, TestGeoUtils, TestBagOfPostings, TestBinaryDocValuesUpdates]
[junit4] Completed [311/508 (1!)] on J0 in 29.13s, 29 tests, 1 error <<< FAILURES!
[...truncated 656 lines...]
[junit4] JVM J0: stdout was not empty, see: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/build/core/test/temp/junit4-J0-20180912_100804_5966825837551503249601.sysout
[junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
[junit4] java.lang.OutOfMemoryError: Java heap space
[junit4] Dumping heap to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/heapdumps/java_pid9836.hprof ...
[junit4] Heap dump file created [425898028 bytes in 0.421 secs]
[junit4] <<< JVM J0: EOF ----
[...truncated 12446 lines...]
[junit4] Suite: org.apache.solr.cloud.MoveReplicaHDFSTest
[junit4] 2> 1873236 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/init-core-data-001
[junit4] 2> 1873237 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=14 numCloses=14
[junit4] 2> 1873237 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1873239 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 1873239 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001
[junit4] 2> 1873239 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1873239 INFO (Thread-53235) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1873239 INFO (Thread-53235) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1873243 ERROR (Thread-53235) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 1873339 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:38166
[junit4] 2> 1873344 INFO (zkConnectionManagerCallback-5632-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873350 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 1873351 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@bc7fc14{/solr,null,AVAILABLE}
[junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4c898fa0{/solr,null,AVAILABLE}
[junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@64601ac3{HTTP/1.1,[http/1.1]}{127.0.0.1:33040}
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3f6a4623{/solr,null,AVAILABLE}
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.Server Started @1873398ms
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33040}
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@ca6060b{HTTP/1.1,[http/1.1]}{127.0.0.1:44645}
[junit4] 2> 1873357 ERROR (jetty-launcher-5629-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.Server Started @1873398ms
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44645}
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-09-12T13:33:38.242Z
[junit4] 2> 1873357 ERROR (jetty-launcher-5629-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-09-12T13:33:38.242Z
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7b71c7ed{HTTP/1.1,[http/1.1]}{127.0.0.1:45413}
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.Server Started @1873399ms
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45413}
[junit4] 2> 1873358 ERROR (jetty-launcher-5629-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-09-12T13:33:38.243Z
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1873359 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@55d441a8{/solr,null,AVAILABLE}
[junit4] 2> 1873359 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@79ba0cf8{HTTP/1.1,[http/1.1]}{127.0.0.1:46777}
[junit4] 2> 1873359 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.Server Started @1873400ms
[junit4] 2> 1873359 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46777}
[junit4] 2> 1873360 ERROR (jetty-launcher-5629-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 1873360 INFO (zkConnectionManagerCallback-5634-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-09-12T13:33:38.245Z
[junit4] 2> 1873360 INFO (zkConnectionManagerCallback-5638-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1873361 INFO (zkConnectionManagerCallback-5636-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873364 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1873365 INFO (zkConnectionManagerCallback-5640-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873367 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1873489 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38166/solr
[junit4] 2> 1873499 INFO (zkConnectionManagerCallback-5644-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873500 DEBUG (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$42/1961168105@ac8e32b
[junit4] 2> 1873514 INFO (zkConnectionManagerCallback-5646-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873534 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38166/solr
[junit4] 2> 1873535 INFO (zkConnectionManagerCallback-5652-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873536 DEBUG (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$42/1961168105@494b597
[junit4] 2> 1873536 INFO (zkConnectionManagerCallback-5654-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873542 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 1873544 DEBUG (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72322882206040072-127.0.0.1:33040_solr-n_0000000000
[junit4] 2> 1873544 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:33040_solr
[junit4] 2> 1873545 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer Overseer (id=72322882206040072-127.0.0.1:33040_solr-n_0000000000) starting
[junit4] 2> 1873550 INFO (zkConnectionManagerCallback-5661-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873550 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873551 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873551 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873551 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873551 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873552 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
[junit4] 2> 1873552 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 1873552 INFO (OverseerStateUpdate-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:33040_solr
[junit4] 2> 1873552 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33040_solr
[junit4] 2> 1873553 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1873553 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873553 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873553 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue-work
[junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
[junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
[junit4] 2> 1873553 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: []
[junit4] 2> 1873557 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 100 elements. ExcludeSet: []
[junit4] 2> 1873557 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 1873558 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/autoscaling.json
[junit4] 2> 1873558 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873558 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1873558 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1873559 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1873559 INFO (zkCallback-5660-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1873559 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873559 INFO (zkCallback-5653-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1873561 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38166/solr
[junit4] 2> 1873562 INFO (zkConnectionManagerCallback-5665-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873562 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 1873563 DEBUG (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$42/1961168105@30045f6
[junit4] 2> 1873564 INFO (zkConnectionManagerCallback-5667-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873567 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:33040_solr]
[junit4] 2> 1873570 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873570 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873571 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1873571 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873571 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873571 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873571 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 1873572 DEBUG (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72322882206040075-127.0.0.1:44645_solr-n_0000000001
[junit4] 2> 1873572 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72322882206040072-127.0.0.1:33040_solr-n_0000000000
[junit4] 2> 1873572 DEBUG (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72322882206040072-127.0.0.1:33040_solr-n_0000000000 to know if I could be the leader
[junit4] 2> 1873573 DEBUG (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:44645_solr as DOWN
[junit4] 2> 1873573 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 1873573 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1873573 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44645_solr
[junit4] 2> 1873574 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873574 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873574 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873575 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1873578 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1873578 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873579 INFO (zkCallback-5660-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1873579 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1873599 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 1873600 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873600 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873600 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 1873600 INFO (zkCallback-5666-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1873600 INFO (zkCallback-5653-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1873600 DEBUG (ScheduledTrigger-8781-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1873601 DEBUG (OverseerStateUpdate-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:44645_solr"} current state version: 0
[junit4] 2> 1873615 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873615 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873616 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1873616 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873616 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873616 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873617 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 1873618 DEBUG (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72322882206040070-127.0.0.1:45413_solr-n_0000000002
[junit4] 2> 1873618 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72322882206040075-127.0.0.1:44645_solr-n_0000000001
[junit4] 2> 1873618 DEBUG (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72322882206040075-127.0.0.1:44645_solr-n_0000000001 to know if I could be the leader
[junit4] 2> 1873618 DEBUG (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:45413_solr as DOWN
[junit4] 2> 1873620 INFO (zkConnectionManagerCallback-5675-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873621 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38166/solr
[junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873622 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1873622 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45413_solr
[junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 1873622 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873622 DEBUG (OverseerStateUpdate-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:45413_solr"} current state version: 0
[junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873627 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873627 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873627 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873627 INFO (zkConnectionManagerCallback-5679-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873628 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
[junit4] 2> 1873628 INFO (zkCallback-5653-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1873628 INFO (zkCallback-5666-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1873628 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1873628 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873628 INFO (zkCallback-5645-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1873631 DEBUG (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$42/1961168105@43a8e7fe
[junit4] 2> 1873632 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33040.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873634 INFO (zkCallback-5660-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1873634 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873635 INFO (zkCallback-5674-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1873647 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33040.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873657 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33040.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873658 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001/node1/.
[junit4] 2> 1873659 INFO (zkConnectionManagerCallback-5682-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873662 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44645.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873667 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873667 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873667 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 1873667 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873668 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873668 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873668 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 1873669 DEBUG (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72322882206040078-127.0.0.1:46777_solr-n_0000000003
[junit4] 2> 1873670 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72322882206040070-127.0.0.1:45413_solr-n_0000000002
[junit4] 2> 1873670 DEBUG (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72322882206040070-127.0.0.1:45413_solr-n_0000000002 to know if I could be the leader
[junit4] 2> 1873670 DEBUG (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:46777_solr as DOWN
[junit4] 2> 1873672 INFO (zkConnectionManagerCallback-5689-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873672 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 1873672 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1873672 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46777_solr
[junit4] 2> 1873672 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 1873672 DEBUG (OverseerStateUpdate-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:46777_solr"} current state version: 0
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873673 INFO (zkCallback-5674-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873673 INFO (zkCallback-5666-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873673 INFO (zkCallback-5660-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1873673 INFO (zkCallback-5653-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873673 INFO (zkCallback-5681-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1873673 INFO (zkCallback-5645-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1873679 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873679 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873680 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1873680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873681 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
[junit4] 2> 1873681 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1873690 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44645.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873690 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44645.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873691 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001/node3/.
[junit4] 2> 1873696 INFO (zkConnectionManagerCallback-5695-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873696 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873697 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873697 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1873697 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873697 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873697 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873697 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
[junit4] 2> 1873698 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1873699 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45413.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873721 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45413.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873721 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46777.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873721 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45413.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873722 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001/node2/.
[junit4] 2> 1873728 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46777.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873728 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46777.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
[junit4] 2> 1873729 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001/node4/.
[junit4] 2> 1873773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 1873773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 1873785 INFO (zkConnectionManagerCallback-5698-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873787 INFO (zkConnectionManagerCallback-5703-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1873788 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 1873788 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 1873788 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1873788 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 1873789 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 1873789 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 1873789 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
[junit4] 2> 1873792 INFO (qtp843545778-70837) [n:127.0.0.1:33040_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
[junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/overseer/collection-queue-work/qnr-0000000000
[junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 1873793 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.ZkDistributedQueue Found child node with improper name: qnr-0000000000
[junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
[junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 1873793 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.ZkDistributedQueue Found child node with improper name: qnr-0000000000
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskQueue Returning topN elements: [/overseer/collection-queue-work/qn-0000000000, ]
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Got 1 tasks from work-queue : [[org.apache.solr.cloud.OverseerTaskQueue$QueueEvent@2e684ecf]]
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Marked task [/overseer/collection-queue-work/qn-0000000000] as running
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Overseer Collection Message Handler: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{"operation":"overseerstatus"}
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 1
[junit4] 2> 1873794 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Runner processing /overseer/collection-queue-work/qn-0000000000
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: [/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 1873794 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler OverseerCollectionMessageHandler.processMessage : overseerstatus , {"operation":"overseerstatus"}
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: [/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 99 elements. ExcludeSet: [/overseer/collection-queue-work/qn-0000000000],[]
[junit4] 2> 1873795 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Completed task:[/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 1873796 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: data: /solr/overseer/collection-queue-work/qnr-0000000000
[junit4] 2> 1873796 DEBUG (zkCallback-5653-thread-2) [ ] o.a.s.c.OverseerTaskQueue NodeDataChanged fired on path /overseer/collection-queue-work/qnr-0000000000 state SyncConnected latchEventType null
[junit4] 2> 1873796 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
[junit4] 2> 1873796 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Marked task [/overseer/collection-queue-work/qn-0000000000] as completed.
[junit4] 2> 1873796 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
[junit4] 2> 1873796 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 1873796 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: [/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 1873796 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: [/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 1873796 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 1873797 INFO (qtp843545778-70837) [n:127.0.0.1:33040_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 1873796 DEBUG (OverseerThreadFactory-8783-thread-1-processing-n:127.0.0.1:33040_solr) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Overseer Collection Message Handler: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{leader=127.0.0.1:33040_solr,overseer_queue_size=0,overseer_work_queue_size=0,overseer_collection_queue_size=2,overseer_operations={am_i_leader={requests=3,errors=0,avgRequestsPerSecond=12.331330215611336,5minRateRequestsPerSecond=0.0,15minRateRequestsPerSecond=0.0,avgTimePerRequest=0.169742,medianRequestTime=0.165008,75thPcRequestTime=0.182126,95thPcRequestTime=0.182126,99thPcRequestTime=0.182126,999thPcRequestTime=0.182126},downnode={requests=3,errors=0,avgRequestsPerSecond=15.424522103702651,5minRateRequestsPerSecond=0.0,15minRateRequestsPerSecond=0.0,avgTimePerRequest=0.007645333333333332,medianRequestTime=0.007875,75thPcRequestTime=0.007913,95thPcRequestTime=0.007913,99thPcRequestTime=0.007913,999thPcRequestTime=0.007913}},collection_operations={am_i_leader={requests=3,errors=0,avgRequestsPerSecond=12.340276611907292,5minRateRequestsPerSecond=0.0,15minRateRequestsPerSecond=0.0,avgTimePerRequest=0.353416,medianRequestTime=0.261802,75thPcRequestTime=0.642363,95thPcRequestTime=0.642363,99thPcRequestTime=0.642363,999thPcRequestTime=0.642363},overseerstatus={requests=0,errors=0,avgRequestsPerSecond=0.0,5minRateRequestsPerSecond=0.0,15minRateRequestsPerSecond=0.0,avgTimePerRequest=0.0,medianRequestTime=0.0,75thPcRequestTime=0.0,95thPcRequestTime=0.0,99thPcRequestTime=0.0,999thPcRequestTime=0.0}},overseer_queue={},overseer_internal_queue={peek={avgRequestsPerSecond=4.133137689332011,5minRateRequestsPerSecond=0.0,15minRateRequestsPerSecond=0.0,avgTimePerRequest=0.225841,medianRequestTime=0.225841,75thPcRequestTime=0.225841,95thPcRequestTime=0.225841,99thPcRequestTime=0.225841,999thPcRequestTime=0.225841}},collection_queue={peektopn_wait2000={avgRequestsPerSecond=4.205752388388952,5minRateRequestsPerSecond=0.0,15minRateRequestsPerSecond=0.0,avgTimePerRequest=236.298596,medianRequestTime=236.298596,75thPcRequestTime=236.298596,95thPcRequestTime=236.298596,99thPcRequestTime=236.298596,999thPcRequestTime=236.298596}}}
[junit4] 2> 1874205 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.h.u.NativeCodeLoader Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 1874606 DEBUG (ScheduledTrigger-8781-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 1874940 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 1875129 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Logging to org.apache.logging.slf4j.Log4jLogger@5537e10f via org.mortbay.log.Slf4jLog
[junit4] 2> 1875153 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 1875228 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 1875272 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/hdfs to ./temp/Jetty_localhost_33738_hdfs____p2z31i/webapp
[junit4] 2> 1875607 DEBUG (ScheduledTrigger-8781-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 1875795 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Got 0 tasks from work-queue : [[]]
[junit4] 2> 1875811 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
[junit4] 2> 1875811 INFO (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 1875811 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
[junit4] 2> 1875811 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 1875812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 1875812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: []
[junit4] 2> 1875812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 100 elements. ExcludeSet: []
[junit4] 2> 1875862 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:33738
[junit4] 2> 1876854 DEBUG (ScheduledTrigger-8781-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 1877674 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 1877679 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 1877695 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_45566_datanode____gaxkl7/webapp
[junit4] 2> 1877812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Got 0 tasks from work-queue : [[]]
[junit4] 2> 1877812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
[junit4] 2> 1877812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
[junit4] 2> 1877812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 1877812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 1877812 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: []
[junit4] 2> 1877813 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 100 elements. ExcludeSet: []
[junit4] 2> 1877854 DEBUG (ScheduledTrigger-8781-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 1878078 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:45566
[junit4] 2> 1878483 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 1878485 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 1878502 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_39156_datanode____aud36b/webapp
[junit4] 2> 1878854 DEBUG (ScheduledTrigger-8781-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 1878874 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:39156
[junit4] 2> 1879290 ERROR (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data3/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data4/]] heartbeating to localhost/127.0.0.1:44527) [ ] o.a.h.h.s.d.DirectoryScanner dfs.datanode.directoryscan.throttle.limit.ms.per.sec set to value below 1 ms/sec. Assuming default value of 1000
[junit4] 2> 1879290 ERROR (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to localhost/127.0.0.1:44527) [ ] o.a.h.h.s.d.DirectoryScanner dfs.datanode.directoryscan.throttle.limit.ms.per.sec set to value below 1 ms/sec. Assuming default value of 1000
[junit4] 2> 1879474 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0xe619e5988ea1c: from storage DS-5d68d4a3-bbf3-4485-8f3d-a6f77b71d80d node DatanodeRegistration(127.0.0.1:45771, datanodeUuid=c8b2f7b4-08df-48aa-b272-8946dedc28c3, infoPort=36504, infoSecurePort=0, ipcPort=46242, storageInfo=lv=-56;cid=testClusterID;nsid=1892984210;c=0), blocks: 0, hasStaleStorage: true, processing time: 2 msecs
[junit4] 2> 1879474 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0xe619e5988e93f: from storage DS-877f8fd7-9349-4768-b707-eb240ef87c4e node DatanodeRegistration(127.0.0.1:36396, datanodeUuid=a22835ed-1487-483a-8378-23b78c4f27d0, infoPort=44555, infoSecurePort=0, ipcPort=39639, storageInfo=lv=-56;cid=testClusterID;nsid=1892984210;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 1879474 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0xe619e5988ea1c: from storage DS-43cabdcf-987f-4457-8039-976895f55535 node DatanodeRegistration(127.0.0.1:45771, datanodeUuid=c8b2f7b4-08df-48aa-b272-8946dedc28c3, infoPort=36504, infoSecurePort=0, ipcPort=46242, storageInfo=lv=-56;cid=testClusterID;nsid=1892984210;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 1879474 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0xe619e5988e93f: from storage DS-98cdc13a-7d43-4a00-b9a2-fb32b3657dac node DatanodeRegistration(127.0.0.1:36396, datanodeUuid=a22835ed-1487-483a-8378-23b78c4f27d0, infoPort=44555, infoSecurePort=0, ipcPort=39639, storageInfo=lv=-56;cid=testClusterID;nsid=1892984210;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 1879813 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Got 0 tasks from work-queue : [[]]
[junit4] 2> 1879813 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
[junit4] 2> 1879813 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor
[...truncated too long message...]
[junit4] 2> 18 /solr/live_nodes
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2> 2 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 2 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2> 2 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 1947439 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
[junit4] 2> 1947470 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
[junit4] 2> 1947571 WARN (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data3/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data4/]] heartbeating to localhost/127.0.0.1:44527) [ ] o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager interrupted
[junit4] 2> 1947573 WARN (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data3/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data4/]] heartbeating to localhost/127.0.0.1:44527) [ ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-1250221142-10.41.0.5-1536759219478 (Datanode Uuid a22835ed-1487-483a-8378-23b78c4f27d0) service to localhost/127.0.0.1:44527
[junit4] 2> 1947580 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
[junit4] 2> 1947598 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
[junit4] 2> 1947699 WARN (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to localhost/127.0.0.1:44527) [ ] o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager interrupted
[junit4] 2> 1947699 WARN (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to localhost/127.0.0.1:44527) [ ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-1250221142-10.41.0.5-1536759219478 (Datanode Uuid c8b2f7b4-08df-48aa-b272-8946dedc28c3) service to localhost/127.0.0.1:44527
[junit4] 2> 1947728 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
[junit4] 2> 1947869 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:38166 38166
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001
[junit4] 2> Sep 12, 2018 1:34:52 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 35 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene80), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@2d33c200), locale=es-CO, timezone=America/Cordoba
[junit4] 2> NOTE: Linux 4.4.0-130-generic amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=4,threads=6,free=217804360,total=517472256
[junit4] 2> NOTE: All tests run in this JVM: [TestConfigSetsAPIZkFailure, TestUnInvertedFieldException, CurrencyFieldTypeTest, TestSolrCLIRunExample, TestQuerySenderListener, TestSortableTextField, SubstringBytesRefFilterTest, BasicAuthStandaloneTest, TestPerFieldSimilarityWithDefaultOverride, TestCloudDeleteByQuery, LegacyCloudClusterPropTest, TestObjectReleaseTracker, TestLazyCores, TestFieldTypeResource, CheckHdfsIndexTest, TestPKIAuthenticationPlugin, TestRawTransformer, EmbeddedSolrNoSerializeTest, AtomicUpdatesTest, TestRecovery, TestIndexSearcher, CurrencyRangeFacetCloudTest, DocumentAnalysisRequestHandlerTest, TriggerSetPropertiesIntegrationTest, TemplateUpdateProcessorTest, TestUninvertingReader, TestHdfsCloudBackupRestore, ShufflingReplicaListTransformerTest, TestOrdValues, SortSpecParsingTest, TestElisionMultitermQuery, PeerSyncWithLeaderTest, SolrSlf4jReporterTest, DocValuesMissingTest, PrimitiveFieldTypeTest, TestLRUCache, TestMacros, ProtectedTermFilterFactoryTest, CustomCollectionTest, TestLeaderElectionZkExpiry, TestSchemaSimilarityResource, MinimalSchemaTest, BlockDirectoryTest, TestSSLRandomization, CoreAdminOperationTest, TestPullReplica, TestApiFramework, TestSolrDeletionPolicy1, SpellCheckCollatorWithCollapseTest, TestExclusionRuleCollectionAccess, TestDefaultStatsCache, TestSolrCoreSnapshots, TestJsonFacets, TestCSVLoader, TestFieldCollectionResource, HighlighterTest, NotRequiredUniqueKeyTest, TestMiniSolrCloudClusterSSL, UUIDUpdateProcessorFallbackTest, DisMaxRequestHandlerTest, TestTolerantSearch, TestLuceneIndexBackCompat, TestRTGBase, SparseHLLTest, TransactionLogTest, AssignTest, PropertiesRequestHandlerTest, OverseerCollectionConfigSetProcessorTest, MetricTriggerIntegrationTest, RangeFacetCloudTest, ExitableDirectoryReaderTest, HdfsAutoAddReplicasIntegrationTest, TestZkAclsWithHadoopAuth, NodeMarkersRegistrationTest, ConfigureRecoveryStrategyTest, ZkCLITest, BJQParserTest, MergeStrategyTest, TestUniqueKeyFieldResource, RankQueryTest, TestSlowCompositeReaderWrapper, SolrCLIZkUtilsTest, TaggerTest, TestManagedResourceStorage, TestOverriddenPrefixQueryForCustomFieldType, TestXmlQParser, TestRandomFaceting, IgnoreCommitOptimizeUpdateProcessorFactoryTest, BigEndianAscendingWordSerializerTest, TimeRoutedAliasUpdateProcessorTest, TestReversedWildcardFilterFactory, DocumentBuilderTest, TestMultiValuedNumericRangeQuery, BlobRepositoryCloudTest, TestSizeLimitedDistributedMap, TestLegacyFieldReuse, SimpleCollectionCreateDeleteTest, TestReqParamsAPI, TestInfoStreamLogging, TestClusterProperties, XmlUpdateRequestHandlerTest, TestExpandComponent, SignatureUpdateProcessorFactoryTest, PeerSyncWithBufferUpdatesTest, TestDelegationWithHadoopAuth, InfoHandlerTest, FastVectorHighlighterTest, SolrRequestParserTest, ShowFileRequestHandlerTest, RemoteQueryErrorTest, SuggesterTSTTest, AutoScalingHandlerTest, HdfsWriteToMultipleCollectionsTest, TriLevelCompositeIdRoutingTest, RequestHandlersTest, ConfigSetsAPITest, TestDynamicLoading, TestPHPSerializedResponseWriter, TestStressInPlaceUpdates, TestAnalyzeInfixSuggestions, UUIDFieldTest, NodeMutatorTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, ReplicaListTransformerTest, TestSolrCloudWithKerberosAlt, EnumFieldTest, CustomHighlightComponentTest, TestUtils, TestSimGenericDistributedQueue, TestEmbeddedSolrServerSchemaAPI, SolrGraphiteReporterTest, SolrInfoBeanTest, TestSolrJ, FileBasedSpellCheckerTest, AnalysisAfterCoreReloadTest, BasicFunctionalityTest, ConvertedLegacyTest, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestDistributedGrouping, TestDistributedMissingSort, TestDistributedSearch, TestDocumentBuilder, TestGroupingSearch, TestHighlightDedupGrouping, TestJoin, ConnectionReuseTest, ActionThrottleTest, AddReplicaTest, AliasIntegrationTest, AssignBackwardCompatibilityTest, AsyncCallRequestStatusResponseTest, BasicDistributedZk2Test, BasicDistributedZkTest, BasicZkTest, ChaosMonkeySafeLeaderWithPullReplicasTest, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, ClusterStateTest, ClusterStateUpdateTest, CollectionPropsTest, CollectionStateFormat2Test, CollectionsAPISolrJTest, DeleteLastCustomShardedReplicaTest, DeleteNodeTest, DeleteReplicaTest, DistribJoinFromCollectionTest, DistributedQueueTest, DocValuesNotIndexedTest, ForceLeaderTest, FullSolrCloudDistribCmdsTest, HealthCheckHandlerTest, HttpPartitionOnCommitTest, LIRRollingUpdatesTest, LeaderElectionContextKeyTest, LeaderElectionIntegrationTest, LeaderFailoverAfterPartitionTest, LeaderFailureAfterFreshStartTest, MigrateRouteKeyTest, MoveReplicaHDFSTest]
[junit4] Completed [470/834 (1!)] on J1 in 84.44s, 4 tests, 1 error, 1 skipped <<< FAILURES!
[...truncated 10123 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/build.xml:651: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/build.xml:585: Some of the tests produced a heap dump, but did not fail. Maybe a suppressed OutOfMemoryError? Dumps created:
* java_pid9836.hprof
Total time: 248 minutes 52 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
Re: [JENKINS] Lucene-Solr-NightlyTests-master - Build # 1640 - Failure
Posted by Dawid Weiss <da...@gmail.com>.
This is an OOM and RAMDirectory -- should this test maybe suppress
RAMDirectory entirely?
D.
On Wed, Sep 12, 2018 at 4:17 PM Apache Jenkins Server
<je...@builds.apache.org> wrote:
>
> Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/1640/
>
> 2 tests failed.
> FAILED: org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates
>
> Error Message:
> Java heap space
>
> Stack Trace:
> java.lang.OutOfMemoryError: Java heap space
> at org.apache.lucene.store.RAMFile.newBuffer(RAMFile.java:84)
> at org.apache.lucene.store.RAMFile.addBuffer(RAMFile.java:57)
> at org.apache.lucene.store.RAMOutputStream.switchCurrentBuffer(RAMOutputStream.java:168)
> at org.apache.lucene.store.RAMOutputStream.writeBytes(RAMOutputStream.java:154)
> at org.apache.lucene.store.MockIndexOutputWrapper.writeBytes(MockIndexOutputWrapper.java:141)
> at org.apache.lucene.codecs.lucene70.Lucene70DocValuesConsumer.addBinaryField(Lucene70DocValuesConsumer.java:348)
> at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addBinaryField(PerFieldDocValuesFormat.java:114)
> at org.apache.lucene.index.ReadersAndUpdates.handleDVUpdates(ReadersAndUpdates.java:330)
> at org.apache.lucene.index.ReadersAndUpdates.writeFieldUpdates(ReadersAndUpdates.java:570)
> at org.apache.lucene.index.IndexWriter.writeSomeDocValuesUpdates(IndexWriter.java:626)
> at org.apache.lucene.index.FrozenBufferedUpdates.apply(FrozenBufferedUpdates.java:299)
> at org.apache.lucene.index.IndexWriter.lambda$publishFrozenUpdates$3(IndexWriter.java:2600)
> at org.apache.lucene.index.IndexWriter$$Lambda$110/1815498900.process(Unknown Source)
> at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5097)
> at org.apache.lucene.index.IndexWriter.updateDocValues(IndexWriter.java:1783)
> at org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates(TestBinaryDocValuesUpdates.java:1324)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1742)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985)
> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
>
>
> FAILED: org.apache.solr.cloud.MoveReplicaHDFSTest.testFailedMove
>
> Error Message:
> No live SolrServers available to handle this request:[http://127.0.0.1:41156/solr/MoveReplicaHDFSTest_failed_coll_true, http://127.0.0.1:46777/solr/MoveReplicaHDFSTest_failed_coll_true]
>
> Stack Trace:
> org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:41156/solr/MoveReplicaHDFSTest_failed_coll_true, http://127.0.0.1:46777/solr/MoveReplicaHDFSTest_failed_coll_true]
> at __randomizedtesting.SeedInfo.seed([A78659BA58953D1C:D4B8A48EF46E8CC]:0)
> at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:462)
> at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1107)
> at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884)
> at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:994)
> at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817)
> at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
> at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942)
> at org.apache.solr.cloud.MoveReplicaTest.testFailedMove(MoveReplicaTest.java:291)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1742)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985)
> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:944)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:830)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:880)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:891)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:41156/solr/MoveReplicaHDFSTest_failed_coll_true: no servers hosting shard: shard2
> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
> at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
> at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:436)
> ... 46 more
>
>
>
>
> Build Log:
> [...truncated 1369 lines...]
> [junit4] Suite: org.apache.lucene.index.TestBinaryDocValuesUpdates
> [junit4] 1> TEST: isNRT=false reader1=StandardDirectoryReader(segments_1:4 _0(8.0.0):C2)
> [junit4] 1> TEST: now reopen
> [junit4] 2> sep 12, 2018 3:46:43 AM com.carrotsearch.randomizedtesting.RandomizedRunner$QueueUncaughtExceptionsHandler uncaughtException
> [junit4] 2> ADVERTENCIA: Uncaught exception in thread: Thread[Lucene Merge Thread #1,5,TGRP-TestBinaryDocValuesUpdates]
> [junit4] 2> org.apache.lucene.index.MergePolicy$MergeException: org.apache.lucene.store.AlreadyClosedException: refusing to delete any files: this IndexWriter hit an unrecoverable exception
> [junit4] 2> at __randomizedtesting.SeedInfo.seed([946FDCB4526E941E]:0)
> [junit4] 2> at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:704)
> [junit4] 2> at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:684)
> [junit4] 2> Caused by: org.apache.lucene.store.AlreadyClosedException: refusing to delete any files: this IndexWriter hit an unrecoverable exception
> [junit4] 2> at org.apache.lucene.index.IndexFileDeleter.ensureOpen(IndexFileDeleter.java:349)
> [junit4] 2> at org.apache.lucene.index.IndexFileDeleter.deleteFiles(IndexFileDeleter.java:669)
> [junit4] 2> at org.apache.lucene.index.IndexFileDeleter.deleteNewFiles(IndexFileDeleter.java:664)
> [junit4] 2> at org.apache.lucene.index.IndexWriter.deleteNewFiles(IndexWriter.java:5015)
> [junit4] 2> at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4530)
> [junit4] 2> at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4066)
> [junit4] 2> at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
> [junit4] 2> at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
> [junit4] 2> Caused by: java.lang.OutOfMemoryError: Java heap space
> [junit4] 2> at org.apache.lucene.store.RAMFile.newBuffer(RAMFile.java:84)
> [junit4] 2> at org.apache.lucene.store.RAMFile.addBuffer(RAMFile.java:57)
> [junit4] 2> at org.apache.lucene.store.RAMOutputStream.switchCurrentBuffer(RAMOutputStream.java:168)
> [junit4] 2> at org.apache.lucene.store.RAMOutputStream.writeBytes(RAMOutputStream.java:154)
> [junit4] 2> at org.apache.lucene.store.MockIndexOutputWrapper.writeBytes(MockIndexOutputWrapper.java:141)
> [junit4] 2> at org.apache.lucene.codecs.lucene70.Lucene70DocValuesConsumer.addBinaryField(Lucene70DocValuesConsumer.java:348)
> [junit4] 2> at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addBinaryField(PerFieldDocValuesFormat.java:114)
> [junit4] 2> at org.apache.lucene.index.ReadersAndUpdates.handleDVUpdates(ReadersAndUpdates.java:330)
> [junit4] 2> at org.apache.lucene.index.ReadersAndUpdates.writeFieldUpdates(ReadersAndUpdates.java:570)
> [junit4] 2> at org.apache.lucene.index.IndexWriter.writeSomeDocValuesUpdates(IndexWriter.java:626)
> [junit4] 2> at org.apache.lucene.index.FrozenBufferedUpdates.apply(FrozenBufferedUpdates.java:299)
> [junit4] 2> at org.apache.lucene.index.IndexWriter.lambda$publishFrozenUpdates$3(IndexWriter.java:2600)
> [junit4] 2> at org.apache.lucene.index.IndexWriter$$Lambda$110/1815498900.process(Unknown Source)
> [junit4] 2> at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5097)
> [junit4] 2> at org.apache.lucene.index.IndexWriter.updateDocValues(IndexWriter.java:1783)
> [junit4] 2> at org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates(TestBinaryDocValuesUpdates.java:1324)
> [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> [junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> [junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498)
> [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1742)
> [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935)
> [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971)
> [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985)
> [junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
> [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> [junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
> [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
> [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
> [junit4] 2>
> [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestBinaryDocValuesUpdates -Dtests.method=testTonsOfUpdates -Dtests.seed=946FDCB4526E941E -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/test-data/enwiki.random.lines.txt -Dtests.locale=es-MX -Dtests.timezone=MST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
> [junit4] ERROR 19.4s J0 | TestBinaryDocValuesUpdates.testTonsOfUpdates <<<
> [junit4] > Throwable #1: java.lang.OutOfMemoryError: Java heap space
> [junit4] > at org.apache.lucene.store.RAMFile.newBuffer(RAMFile.java:84)
> [junit4] > at org.apache.lucene.store.RAMFile.addBuffer(RAMFile.java:57)
> [junit4] > at org.apache.lucene.store.RAMOutputStream.switchCurrentBuffer(RAMOutputStream.java:168)
> [junit4] > at org.apache.lucene.store.RAMOutputStream.writeBytes(RAMOutputStream.java:154)
> [junit4] > at org.apache.lucene.store.MockIndexOutputWrapper.writeBytes(MockIndexOutputWrapper.java:141)
> [junit4] > at org.apache.lucene.codecs.lucene70.Lucene70DocValuesConsumer.addBinaryField(Lucene70DocValuesConsumer.java:348)
> [junit4] > at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addBinaryField(PerFieldDocValuesFormat.java:114)
> [junit4] > at org.apache.lucene.index.ReadersAndUpdates.handleDVUpdates(ReadersAndUpdates.java:330)
> [junit4] > at org.apache.lucene.index.ReadersAndUpdates.writeFieldUpdates(ReadersAndUpdates.java:570)
> [junit4] > at org.apache.lucene.index.IndexWriter.writeSomeDocValuesUpdates(IndexWriter.java:626)
> [junit4] > at org.apache.lucene.index.FrozenBufferedUpdates.apply(FrozenBufferedUpdates.java:299)
> [junit4] > at org.apache.lucene.index.IndexWriter.lambda$publishFrozenUpdates$3(IndexWriter.java:2600)
> [junit4] > at org.apache.lucene.index.IndexWriter$$Lambda$110/1815498900.process(Unknown Source)
> [junit4] > at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5097)
> [junit4] > at org.apache.lucene.index.IndexWriter.updateDocValues(IndexWriter.java:1783)
> [junit4] > at org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates(TestBinaryDocValuesUpdates.java:1324)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3595, name=Lucene Merge Thread #1, state=RUNNABLE, group=TGRP-TestBinaryDocValuesUpdates]
> [junit4] > Caused by: org.apache.lucene.index.MergePolicy$MergeException: org.apache.lucene.store.AlreadyClosedException: refusing to delete any files: this IndexWriter hit an unrecoverable exception
> [junit4] > at __randomizedtesting.SeedInfo.seed([946FDCB4526E941E]:0)
> [junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:704)
> [junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:684)
> [junit4] > Caused by: org.apache.lucene.store.AlreadyClosedException: refusing to delete any files: this IndexWriter hit an unrecoverable exception
> [junit4] > at org.apache.lucene.index.IndexFileDeleter.ensureOpen(IndexFileDeleter.java:349)
> [junit4] > at org.apache.lucene.index.IndexFileDeleter.deleteFiles(IndexFileDeleter.java:669)
> [junit4] > at org.apache.lucene.index.IndexFileDeleter.deleteNewFiles(IndexFileDeleter.java:664)
> [junit4] > at org.apache.lucene.index.IndexWriter.deleteNewFiles(IndexWriter.java:5015)
> [junit4] > at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4530)
> [junit4] > at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4066)
> [junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
> [junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
> [junit4] > Caused by: java.lang.OutOfMemoryError: Java heap space
> [junit4] > at org.apache.lucene.store.RAMFile.newBuffer(RAMFile.java:84)
> [junit4] > at org.apache.lucene.store.RAMFile.addBuffer(RAMFile.java:57)
> [junit4] > at org.apache.lucene.store.RAMOutputStream.switchCurrentBuffer(RAMOutputStream.java:168)
> [junit4] > at org.apache.lucene.store.RAMOutputStream.writeBytes(RAMOutputStream.java:154)
> [junit4] > at org.apache.lucene.store.MockIndexOutputWrapper.writeBytes(MockIndexOutputWrapper.java:141)
> [junit4] > at org.apache.lucene.codecs.lucene70.Lucene70DocValuesConsumer.addBinaryField(Lucene70DocValuesConsumer.java:348)
> [junit4] > at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addBinaryField(PerFieldDocValuesFormat.java:114)
> [junit4] > at org.apache.lucene.index.ReadersAndUpdates.handleDVUpdates(ReadersAndUpdates.java:330)
> [junit4] > at org.apache.lucene.index.ReadersAndUpdates.writeFieldUpdates(ReadersAndUpdates.java:570)
> [junit4] > at org.apache.lucene.index.IndexWriter.writeSomeDocValuesUpdates(IndexWriter.java:626)
> [junit4] > at org.apache.lucene.index.FrozenBufferedUpdates.apply(FrozenBufferedUpdates.java:299)
> [junit4] > at org.apache.lucene.index.IndexWriter.lambda$publishFrozenUpdates$3(IndexWriter.java:2600)
> [junit4] > at org.apache.lucene.index.IndexWriter$$Lambda$110/1815498900.process(Unknown Source)
> [junit4] > at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5097)
> [junit4] > at org.apache.lucene.index.IndexWriter.updateDocValues(IndexWriter.java:1783)
> [junit4] > at org.apache.lucene.index.TestBinaryDocValuesUpdates.testTonsOfUpdates(TestBinaryDocValuesUpdates.java:1324)
> [junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/build/core/test/J0/temp/lucene.index.TestBinaryDocValuesUpdates_946FDCB4526E941E-001
> [junit4] 2> NOTE: test params are: codec=Asserting(Lucene80): {bdv=PostingsFormat(name=MockRandom), k1=PostingsFormat(name=Asserting), f=PostingsFormat(name=Asserting), k2=PostingsFormat(name=LuceneVarGapFixedInterval), foo=PostingsFormat(name=Asserting), dvUpdateKey=PostingsFormat(name=MockRandom), upd=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), updKey=PostingsFormat(name=Asserting), id=PostingsFormat(name=LuceneVarGapFixedInterval), key=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{ndv=DocValuesFormat(name=Asserting), f10=DocValuesFormat(name=Lucene70), f12=DocValuesFormat(name=Direct), f11=DocValuesFormat(name=Lucene70), f14=DocValuesFormat(name=Lucene70), f13=DocValuesFormat(name=Asserting), f0=DocValuesFormat(name=Lucene70), f16=DocValuesFormat(name=Direct), f1=DocValuesFormat(name=Direct), f15=DocValuesFormat(name=Lucene70), f2=DocValuesFormat(name=Asserting), f18=DocValuesFormat(name=Lucene70), f3=DocValuesFormat(name=Lucene70), f17=DocValuesFormat(name=Asserting), f4=DocValuesFormat(name=Lucene70), f19=DocValuesFormat(name=Lucene70), f5=DocValuesFormat(name=Direct), bdv2=DocValuesFormat(name=Lucene70), f6=DocValuesFormat(name=Asserting), f7=DocValuesFormat(name=Lucene70), number=DocValuesFormat(name=Direct), f8=DocValuesFormat(name=Lucene70), bdv1=DocValuesFormat(name=Lucene70), f9=DocValuesFormat(name=Direct), id=DocValuesFormat(name=Direct), val=DocValuesFormat(name=Lucene70), f21=DocValuesFormat(name=Lucene70), f20=DocValuesFormat(name=Asserting), f23=DocValuesFormat(name=Direct), f22=DocValuesFormat(name=Lucene70), f25=DocValuesFormat(name=Lucene70), upd=DocValuesFormat(name=Lucene70), f24=DocValuesFormat(name=Asserting), f27=DocValuesFormat(name=Direct), f26=DocValuesFormat(name=Lucene70), sort=DocValuesFormat(name=Lucene70), cf0=DocValuesFormat(name=Lucene70), f29=DocValuesFormat(name=Lucene70), f28=DocValuesFormat(name=Asserting), cf2=DocValuesFormat(name=Direct), cf1=DocValuesFormat(name=Lucene70), cf4=DocValuesFormat(name=Lucene70), cf3=DocValuesFormat(name=Asserting), cf6=DocValuesFormat(name=Direct), cf5=DocValuesFormat(name=Lucene70), cf8=DocValuesFormat(name=Lucene70), cf7=DocValuesFormat(name=Asserting), cf9=DocValuesFormat(name=Lucene70), ssdv=DocValuesFormat(name=Lucene70), sdv=DocValuesFormat(name=Lucene70), cf29=DocValuesFormat(name=Lucene70), cf27=DocValuesFormat(name=Asserting), cf28=DocValuesFormat(name=Lucene70), cf25=DocValuesFormat(name=Lucene70), cf26=DocValuesFormat(name=Direct), cf23=DocValuesFormat(name=Asserting), cf24=DocValuesFormat(name=Lucene70), cf21=DocValuesFormat(name=Lucene70), cf22=DocValuesFormat(name=Direct), cf20=DocValuesFormat(name=Lucene70), key=DocValuesFormat(name=Direct), cf=DocValuesFormat(name=Direct), cf18=DocValuesFormat(name=Lucene70), cf19=DocValuesFormat(name=Direct), f=DocValuesFormat(name=Lucene70), cf16=DocValuesFormat(name=Asserting), cf17=DocValuesFormat(name=Lucene70), cf14=DocValuesFormat(name=Lucene70), cf15=DocValuesFormat(name=Direct), cf12=DocValuesFormat(name=Asserting), control=DocValuesFormat(name=Lucene70), cf13=DocValuesFormat(name=Lucene70), cf10=DocValuesFormat(name=Lucene70), cf11=DocValuesFormat(name=Direct), bdv=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=1444, maxMBSortInHeap=6.796784115105444, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@30cec53a), locale=es-MX, timezone=MST
> [junit4] 2> NOTE: Linux 4.4.0-130-generic amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=4,threads=1,free=87571128,total=477626368
> [junit4] 2> NOTE: All tests run in this JVM: [TestLatLonPointDistanceSort, TestExitableDirectoryReader, TestSpanOrQuery, TestOfflineSorter, TestPayloadsOnVectors, TestNamedSPILoader, TestUnicodeUtil, TestGraphTokenizers, TestIndexedDISI, TestTransactions, TestSparseFixedBitDocIdSet, TestFloatRangeFieldQueries, TestIndexWriterOnJRECrash, TestBinaryTerms, TestIOUtils, TestIndexWriterDelete, TestIndexWriterMerging, TestBytesRefAttImpl, TestShardSearching, TestWeakIdentityMap, TestDateSort, TestPrefixQuery, TestSearchWithThreads, TestAutomaton, MultiCollectorTest, TestQueryBuilder, TestLazyProxSkipping, TestSpans, Test2BNumericDocValues, TestAxiomaticSimilarity, TestCompetitiveFreqNormAccumulator, TestUTF32ToUTF8, TestRollback, TestCodecHoldsOpenFiles, TestLongRangeFieldQueries, TestSegmentInfos, TestStringMSBRadixSorter, TestDoubleValuesSource, TestLucene50LiveDocsFormat, TestMultiThreadTermVectors, TestSortedSetDocValues, TestMultiMMap, TestBytesRef, TestRollingBuffer, TestCharsRef, TestSpanExplanations, TestNoDeletionPolicy, TestMultiTermsEnum, TestIndexSearcher, TestTermStates, TestBytesStore, TestNeedsScores, TestSumDocFreq, TestIndexWriterLockRelease, TestHugeRamFile, TestCollectionUtil, TestFilterDirectoryReader, TestDemoParallelLeafReader, TestLucene70SegmentInfoFormat, TestReaderClosed, TestLatLonDocValuesQueries, Test2BSortedDocValuesOrds, TestIndexWriterExceptions2, TestFieldMaskingSpanQuery, TestAutomatonQuery, Test2BPostings, TestManyFields, TestGeoEncodingUtils, TestIndexInput, TestOmitPositions, TestReqExclBulkScorer, TestAddIndexes, TestParallelReaderEmptyIndex, TestInfoStream, TestTermsEnum, TestIndependenceStandardized, TestComplexExplanationsOfNonMatches, TestHighCompressionMode, TestBooleanSimilarity, TestAllFilesHaveChecksumFooter, TestSimpleSearchEquivalence, TestDocValuesIndexing, TestSetOnce, TestSnapshotDeletionPolicy, TestDocument, TestBinaryDocument, TestDateTools, TestField, TestIntRange, TestGeoUtils, TestBagOfPostings, TestBinaryDocValuesUpdates]
> [junit4] Completed [311/508 (1!)] on J0 in 29.13s, 29 tests, 1 error <<< FAILURES!
>
> [...truncated 656 lines...]
> [junit4] JVM J0: stdout was not empty, see: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/build/core/test/temp/junit4-J0-20180912_100804_5966825837551503249601.sysout
> [junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
> [junit4] java.lang.OutOfMemoryError: Java heap space
> [junit4] Dumping heap to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/heapdumps/java_pid9836.hprof ...
> [junit4] Heap dump file created [425898028 bytes in 0.421 secs]
> [junit4] <<< JVM J0: EOF ----
>
> [...truncated 12446 lines...]
> [junit4] Suite: org.apache.solr.cloud.MoveReplicaHDFSTest
> [junit4] 2> 1873236 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
> [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/init-core-data-001
> [junit4] 2> 1873237 WARN (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=14 numCloses=14
> [junit4] 2> 1873237 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
> [junit4] 2> 1873239 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
> [junit4] 2> 1873239 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001
> [junit4] 2> 1873239 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
> [junit4] 2> 1873239 INFO (Thread-53235) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
> [junit4] 2> 1873239 INFO (Thread-53235) [ ] o.a.s.c.ZkTestServer Starting server
> [junit4] 2> 1873243 ERROR (Thread-53235) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
> [junit4] 2> 1873339 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:38166
> [junit4] 2> 1873344 INFO (zkConnectionManagerCallback-5632-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873350 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
> [junit4] 2> 1873351 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
> [junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
> [junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
> [junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
> [junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
> [junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
> [junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
> [junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
> [junit4] 2> 1873352 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@bc7fc14{/solr,null,AVAILABLE}
> [junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4c898fa0{/solr,null,AVAILABLE}
> [junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
> [junit4] 2> 1873356 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.session node0 Scavenging every 660000ms
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@64601ac3{HTTP/1.1,[http/1.1]}{127.0.0.1:33040}
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3f6a4623{/solr,null,AVAILABLE}
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.e.j.s.Server Started @1873398ms
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33040}
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@ca6060b{HTTP/1.1,[http/1.1]}{127.0.0.1:44645}
> [junit4] 2> 1873357 ERROR (jetty-launcher-5629-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.e.j.s.Server Started @1873398ms
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44645}
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-09-12T13:33:38.242Z
> [junit4] 2> 1873357 ERROR (jetty-launcher-5629-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 1873357 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-09-12T13:33:38.242Z
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7b71c7ed{HTTP/1.1,[http/1.1]}{127.0.0.1:45413}
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.e.j.s.Server Started @1873399ms
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45413}
> [junit4] 2> 1873358 ERROR (jetty-launcher-5629-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-09-12T13:33:38.243Z
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
> [junit4] 2> 1873358 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
> [junit4] 2> 1873359 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@55d441a8{/solr,null,AVAILABLE}
> [junit4] 2> 1873359 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@79ba0cf8{HTTP/1.1,[http/1.1]}{127.0.0.1:46777}
> [junit4] 2> 1873359 INFO (jetty-launcher-5629-thread-3) [ ] o.e.j.s.Server Started @1873400ms
> [junit4] 2> 1873359 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46777}
> [junit4] 2> 1873360 ERROR (jetty-launcher-5629-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
> [junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
> [junit4] 2> 1873360 INFO (zkConnectionManagerCallback-5634-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-09-12T13:33:38.245Z
> [junit4] 2> 1873360 INFO (zkConnectionManagerCallback-5638-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 1873360 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 1873361 INFO (zkConnectionManagerCallback-5636-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873364 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 1873365 INFO (zkConnectionManagerCallback-5640-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873367 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 1873489 INFO (jetty-launcher-5629-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38166/solr
> [junit4] 2> 1873499 INFO (zkConnectionManagerCallback-5644-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873500 DEBUG (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$42/1961168105@ac8e32b
> [junit4] 2> 1873514 INFO (zkConnectionManagerCallback-5646-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873534 INFO (jetty-launcher-5629-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38166/solr
> [junit4] 2> 1873535 INFO (zkConnectionManagerCallback-5652-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873536 DEBUG (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$42/1961168105@494b597
> [junit4] 2> 1873536 INFO (zkConnectionManagerCallback-5654-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873541 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873542 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
> [junit4] 2> 1873544 DEBUG (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72322882206040072-127.0.0.1:33040_solr-n_0000000000
> [junit4] 2> 1873544 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:33040_solr
> [junit4] 2> 1873545 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer Overseer (id=72322882206040072-127.0.0.1:33040_solr-n_0000000000) starting
> [junit4] 2> 1873550 INFO (zkConnectionManagerCallback-5661-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873550 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873551 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873551 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873551 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873551 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873552 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
> [junit4] 2> 1873552 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
> [junit4] 2> 1873552 INFO (OverseerStateUpdate-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:33040_solr
> [junit4] 2> 1873552 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33040_solr
> [junit4] 2> 1873553 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
> [junit4] 2> 1873553 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873553 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873553 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue-work
> [junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
> [junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
> [junit4] 2> 1873553 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
> [junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
> [junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
> [junit4] 2> 1873553 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: []
> [junit4] 2> 1873557 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 100 elements. ExcludeSet: []
> [junit4] 2> 1873557 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
> [junit4] 2> 1873558 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/autoscaling.json
> [junit4] 2> 1873558 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873558 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
> [junit4] 2> 1873558 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
> [junit4] 2> 1873559 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
> [junit4] 2> 1873559 INFO (zkCallback-5660-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 1873559 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873559 INFO (zkCallback-5653-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 1873561 INFO (jetty-launcher-5629-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38166/solr
> [junit4] 2> 1873562 INFO (zkConnectionManagerCallback-5665-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873562 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/autoscaling/events/.scheduled_maintenance
> [junit4] 2> 1873563 DEBUG (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$42/1961168105@30045f6
> [junit4] 2> 1873564 INFO (zkConnectionManagerCallback-5667-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873567 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:33040_solr]
> [junit4] 2> 1873570 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873570 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873571 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 1873571 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873571 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873571 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873571 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
> [junit4] 2> 1873572 DEBUG (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72322882206040075-127.0.0.1:44645_solr-n_0000000001
> [junit4] 2> 1873572 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72322882206040072-127.0.0.1:33040_solr-n_0000000000
> [junit4] 2> 1873572 DEBUG (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72322882206040072-127.0.0.1:33040_solr-n_0000000000 to know if I could be the leader
> [junit4] 2> 1873573 DEBUG (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:44645_solr as DOWN
> [junit4] 2> 1873573 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
> [junit4] 2> 1873573 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
> [junit4] 2> 1873573 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44645_solr
> [junit4] 2> 1873574 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873574 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873574 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873575 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
> [junit4] 2> 1873578 DEBUG (OverseerAutoScalingTriggerThread-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
> [junit4] 2> 1873578 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873579 INFO (zkCallback-5660-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
> [junit4] 2> 1873579 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
> [junit4] 2> 1873599 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/autoscaling/events/.auto_add_replicas
> [junit4] 2> 1873600 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873600 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873600 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
> [junit4] 2> 1873600 INFO (zkCallback-5666-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
> [junit4] 2> 1873600 INFO (zkCallback-5653-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
> [junit4] 2> 1873600 DEBUG (ScheduledTrigger-8781-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 1873601 DEBUG (OverseerStateUpdate-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
> [junit4] 2> "operation":"downnode",
> [junit4] 2> "node_name":"127.0.0.1:44645_solr"} current state version: 0
> [junit4] 2> 1873615 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873615 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873616 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
> [junit4] 2> 1873616 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873616 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873616 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873617 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
> [junit4] 2> 1873618 DEBUG (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72322882206040070-127.0.0.1:45413_solr-n_0000000002
> [junit4] 2> 1873618 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72322882206040075-127.0.0.1:44645_solr-n_0000000001
> [junit4] 2> 1873618 DEBUG (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72322882206040075-127.0.0.1:44645_solr-n_0000000001 to know if I could be the leader
> [junit4] 2> 1873618 DEBUG (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:45413_solr as DOWN
> [junit4] 2> 1873620 INFO (zkConnectionManagerCallback-5675-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873621 INFO (jetty-launcher-5629-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38166/solr
> [junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
> [junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873622 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
> [junit4] 2> 1873622 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45413_solr
> [junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
> [junit4] 2> 1873622 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
> [junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873622 DEBUG (OverseerStateUpdate-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
> [junit4] 2> "operation":"downnode",
> [junit4] 2> "node_name":"127.0.0.1:45413_solr"} current state version: 0
> [junit4] 2> 1873622 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873623 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873627 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873627 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873627 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873627 INFO (zkConnectionManagerCallback-5679-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873628 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
> [junit4] 2> 1873628 INFO (zkCallback-5653-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 1873628 INFO (zkCallback-5666-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 1873628 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
> [junit4] 2> 1873628 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873628 INFO (zkCallback-5645-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 1873631 DEBUG (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$42/1961168105@43a8e7fe
> [junit4] 2> 1873632 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33040.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873634 INFO (zkCallback-5660-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 1873634 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873635 INFO (zkCallback-5674-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 1873647 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33040.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873657 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33040.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873658 INFO (jetty-launcher-5629-thread-2) [n:127.0.0.1:33040_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001/node1/.
> [junit4] 2> 1873659 INFO (zkConnectionManagerCallback-5682-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873662 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44645.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873667 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873667 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873667 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
> [junit4] 2> 1873667 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873668 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873668 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873668 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
> [junit4] 2> 1873669 DEBUG (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72322882206040078-127.0.0.1:46777_solr-n_0000000003
> [junit4] 2> 1873670 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72322882206040070-127.0.0.1:45413_solr-n_0000000002
> [junit4] 2> 1873670 DEBUG (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72322882206040070-127.0.0.1:45413_solr-n_0000000002 to know if I could be the leader
> [junit4] 2> 1873670 DEBUG (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:46777_solr as DOWN
> [junit4] 2> 1873672 INFO (zkConnectionManagerCallback-5689-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873672 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
> [junit4] 2> 1873672 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
> [junit4] 2> 1873672 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46777_solr
> [junit4] 2> 1873672 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
> [junit4] 2> 1873672 DEBUG (OverseerStateUpdate-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
> [junit4] 2> "operation":"downnode",
> [junit4] 2> "node_name":"127.0.0.1:46777_solr"} current state version: 0
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873673 INFO (zkCallback-5674-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873673 INFO (zkCallback-5666-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873673 INFO (zkCallback-5660-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 1873673 INFO (zkCallback-5653-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873673 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873673 INFO (zkCallback-5681-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 1873673 INFO (zkCallback-5645-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 1873679 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873679 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873680 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
> [junit4] 2> 1873680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873680 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873681 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
> [junit4] 2> 1873681 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
> [junit4] 2> 1873690 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44645.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873690 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44645.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873691 INFO (jetty-launcher-5629-thread-4) [n:127.0.0.1:44645_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001/node3/.
> [junit4] 2> 1873696 INFO (zkConnectionManagerCallback-5695-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873696 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873697 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873697 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
> [junit4] 2> 1873697 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873697 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873697 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873697 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
> [junit4] 2> 1873698 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
> [junit4] 2> 1873699 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45413.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873721 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45413.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873721 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46777.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873721 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45413.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873722 INFO (jetty-launcher-5629-thread-1) [n:127.0.0.1:45413_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001/node2/.
> [junit4] 2> 1873728 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46777.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873728 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46777.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c63816
> [junit4] 2> 1873729 INFO (jetty-launcher-5629-thread-3) [n:127.0.0.1:46777_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSTest_A78659BA58953D1C-001/tempDir-001/node4/.
> [junit4] 2> 1873773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
> [junit4] 2> 1873773 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
> [junit4] 2> 1873785 INFO (zkConnectionManagerCallback-5698-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873787 INFO (zkConnectionManagerCallback-5703-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 1873788 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
> [junit4] 2> 1873788 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
> [junit4] 2> 1873788 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
> [junit4] 2> 1873788 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
> [junit4] 2> 1873789 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
> [junit4] 2> 1873789 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
> [junit4] 2> 1873789 INFO (SUITE-MoveReplicaHDFSTest-seed#[A78659BA58953D1C]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38166/solr ready
> [junit4] 2> 1873792 INFO (qtp843545778-70837) [n:127.0.0.1:33040_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
> [junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/overseer/collection-queue-work/qnr-0000000000
> [junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
> [junit4] 2> 1873793 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.ZkDistributedQueue Found child node with improper name: qnr-0000000000
> [junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
> [junit4] 2> 1873793 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
> [junit4] 2> 1873793 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.ZkDistributedQueue Found child node with improper name: qnr-0000000000
> [junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskQueue Returning topN elements: [/overseer/collection-queue-work/qn-0000000000, ]
> [junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040_solr-n_0000000000) [n:127.0.0.1:33040_solr ] o.a.s.c.OverseerTaskProcessor Got 1 tasks from work-queue : [[org.apache.solr.cloud.OverseerTaskQueue$QueueEvent@2e684ecf]]
> [junit4] 2> 1873794 DEBUG (OverseerCollectionConfigSetProcessor-72322882206040072-127.0.0.1:33040
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org