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 2017/03/08 13:38:23 UTC
[JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
Unstable
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
2 tests failed.
FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
Error Message:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
Stack Trace:
java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
at __randomizedtesting.SeedInfo.seed([4609011308FB57E6:E4D14FC96C097EE0]:0)
at org.apache.lucene.mockfile.HandleLimitFS.onOpen(HandleLimitFS.java:48)
at org.apache.lucene.mockfile.HandleTrackingFS.callOpenHook(HandleTrackingFS.java:81)
at org.apache.lucene.mockfile.HandleTrackingFS.newFileChannel(HandleTrackingFS.java:197)
at org.apache.lucene.mockfile.HandleTrackingFS.newFileChannel(HandleTrackingFS.java:166)
at org.apache.lucene.mockfile.FilterFileSystemProvider.newFileChannel(FilterFileSystemProvider.java:202)
at java.nio.channels.FileChannel.open(FileChannel.java:287)
at java.nio.channels.FileChannel.open(FileChannel.java:335)
at org.apache.lucene.store.NIOFSDirectory.openInput(NIOFSDirectory.java:81)
at org.apache.lucene.util.LuceneTestCase.slowFileExists(LuceneTestCase.java:2741)
at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:749)
at org.apache.lucene.codecs.blocktree.BlockTreeTermsReader.<init>(BlockTreeTermsReader.java:153)
at org.apache.lucene.codecs.lucene50.Lucene50PostingsFormat.fieldsProducer(Lucene50PostingsFormat.java:445)
at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.<init>(PerFieldPostingsFormat.java:292)
at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat.fieldsProducer(PerFieldPostingsFormat.java:372)
at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:112)
at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:74)
at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:145)
at org.apache.lucene.index.BufferedUpdatesStream$SegmentState.<init>(BufferedUpdatesStream.java:384)
at org.apache.lucene.index.BufferedUpdatesStream.openSegmentStates(BufferedUpdatesStream.java:416)
at org.apache.lucene.index.BufferedUpdatesStream.applyDeletesAndUpdates(BufferedUpdatesStream.java:261)
at org.apache.lucene.index.IndexWriter.applyAllDeletesAndUpdates(IndexWriter.java:3464)
at org.apache.lucene.index.IndexWriter.applyDeletesAndPurge(IndexWriter.java:4992)
at org.apache.lucene.index.DocumentsWriter$ApplyDeletesEvent.process(DocumentsWriter.java:717)
at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5042)
at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5033)
at org.apache.lucene.index.IndexWriter.deleteDocuments(IndexWriter.java:1509)
at org.apache.lucene.index.TestIndexSorting.testRandom3(TestIndexSorting.java:2237)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
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:745)
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload
Error Message:
expected:<[{indexVersion=1488977341443,generation=2,filelist=[_1hx.cfe, _1hx.cfs, _1hx.si, _1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i1.cfe, _1i1.cfs, _1i1.si, _1i2.cfe, _1i2.cfs, _1i2.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i4.cfe, _1i4.cfs, _1i4.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i6.cfe, _1i6.cfs, _1i6.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1i9.cfe, _1i9.cfs, _1i9.si, _1ia.cfe, _1ia.cfs, _1ia.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1id.cfe, _1id.cfs, _1id.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1if.cfe, _1if.cfs, _1if.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1ij.cfe, _1ij.cfs, _1ij.si, _1ik.cfe, _1ik.cfs, _1ik.si, segments_2]}]> but was:<[{indexVersion=1488977341443,generation=2,filelist=[_1hx.cfe, _1hx.cfs, _1hx.si, _1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i1.cfe, _1i1.cfs, _1i1.si, _1i2.cfe, _1i2.cfs, _1i2.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i4.cfe, _1i4.cfs, _1i4.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i6.cfe, _1i6.cfs, _1i6.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1i9.cfe, _1i9.cfs, _1i9.si, _1ia.cfe, _1ia.cfs, _1ia.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1id.cfe, _1id.cfs, _1id.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1if.cfe, _1if.cfs, _1if.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1ij.cfe, _1ij.cfs, _1ij.si, _1ik.cfe, _1ik.cfs, _1ik.si, segments_2]}, {indexVersion=1488977341443,generation=3,filelist=[_1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1il.cfe, _1il.cfs, _1il.si, segments_3]}]>
Stack Trace:
java.lang.AssertionError: expected:<[{indexVersion=1488977341443,generation=2,filelist=[_1hx.cfe, _1hx.cfs, _1hx.si, _1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i1.cfe, _1i1.cfs, _1i1.si, _1i2.cfe, _1i2.cfs, _1i2.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i4.cfe, _1i4.cfs, _1i4.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i6.cfe, _1i6.cfs, _1i6.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1i9.cfe, _1i9.cfs, _1i9.si, _1ia.cfe, _1ia.cfs, _1ia.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1id.cfe, _1id.cfs, _1id.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1if.cfe, _1if.cfs, _1if.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1ij.cfe, _1ij.cfs, _1ij.si, _1ik.cfe, _1ik.cfs, _1ik.si, segments_2]}]> but was:<[{indexVersion=1488977341443,generation=2,filelist=[_1hx.cfe, _1hx.cfs, _1hx.si, _1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i1.cfe, _1i1.cfs, _1i1.si, _1i2.cfe, _1i2.cfs, _1i2.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i4.cfe, _1i4.cfs, _1i4.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i6.cfe, _1i6.cfs, _1i6.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1i9.cfe, _1i9.cfs, _1i9.si, _1ia.cfe, _1ia.cfs, _1ia.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1id.cfe, _1id.cfs, _1id.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1if.cfe, _1if.cfs, _1if.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1ij.cfe, _1ij.cfs, _1ij.si, _1ik.cfe, _1ik.cfs, _1ik.si, segments_2]}, {indexVersion=1488977341443,generation=3,filelist=[_1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1il.cfe, _1il.cfs, _1il.si, segments_3]}]>
at __randomizedtesting.SeedInfo.seed([829C4BD9B8CDAE69:A74B50E9C885A06A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:147)
at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1281)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
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:745)
Build Log:
[...truncated 277 lines...]
[junit4] Suite: org.apache.lucene.index.TestIndexSorting
[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=TestIndexSorting -Dtests.method=testRandom3 -Dtests.seed=4609011308FB57E6 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/test-data/enwiki.random.lines.txt -Dtests.locale=es-MX -Dtests.timezone=America/El_Salvador -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 105s J2 | TestIndexSorting.testRandom3 <<<
[junit4] > Throwable #1: java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
[junit4] > at __randomizedtesting.SeedInfo.seed([4609011308FB57E6:E4D14FC96C097EE0]:0)
[junit4] > at org.apache.lucene.mockfile.HandleLimitFS.onOpen(HandleLimitFS.java:48)
[junit4] > at org.apache.lucene.mockfile.HandleTrackingFS.callOpenHook(HandleTrackingFS.java:81)
[junit4] > at org.apache.lucene.mockfile.HandleTrackingFS.newFileChannel(HandleTrackingFS.java:197)
[junit4] > at org.apache.lucene.mockfile.HandleTrackingFS.newFileChannel(HandleTrackingFS.java:166)
[junit4] > at org.apache.lucene.mockfile.FilterFileSystemProvider.newFileChannel(FilterFileSystemProvider.java:202)
[junit4] > at java.nio.channels.FileChannel.open(FileChannel.java:287)
[junit4] > at java.nio.channels.FileChannel.open(FileChannel.java:335)
[junit4] > at org.apache.lucene.store.NIOFSDirectory.openInput(NIOFSDirectory.java:81)
[junit4] > at org.apache.lucene.util.LuceneTestCase.slowFileExists(LuceneTestCase.java:2741)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:749)
[junit4] > at org.apache.lucene.codecs.blocktree.BlockTreeTermsReader.<init>(BlockTreeTermsReader.java:153)
[junit4] > at org.apache.lucene.codecs.lucene50.Lucene50PostingsFormat.fieldsProducer(Lucene50PostingsFormat.java:445)
[junit4] > at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.<init>(PerFieldPostingsFormat.java:292)
[junit4] > at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat.fieldsProducer(PerFieldPostingsFormat.java:372)
[junit4] > at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:112)
[junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:74)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:145)
[junit4] > at org.apache.lucene.index.BufferedUpdatesStream$SegmentState.<init>(BufferedUpdatesStream.java:384)
[junit4] > at org.apache.lucene.index.BufferedUpdatesStream.openSegmentStates(BufferedUpdatesStream.java:416)
[junit4] > at org.apache.lucene.index.BufferedUpdatesStream.applyDeletesAndUpdates(BufferedUpdatesStream.java:261)
[junit4] > at org.apache.lucene.index.IndexWriter.applyAllDeletesAndUpdates(IndexWriter.java:3464)
[junit4] > at org.apache.lucene.index.IndexWriter.applyDeletesAndPurge(IndexWriter.java:4992)
[junit4] > at org.apache.lucene.index.DocumentsWriter$ApplyDeletesEvent.process(DocumentsWriter.java:717)
[junit4] > at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5042)
[junit4] > at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5033)
[junit4] > at org.apache.lucene.index.IndexWriter.deleteDocuments(IndexWriter.java:1509)
[junit4] > at org.apache.lucene.index.TestIndexSorting.testRandom3(TestIndexSorting.java:2237)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001
[junit4] 2> NOTE: test params are: codec=Lucene62, sim=RandomSimilarity(queryNorm=true,coord=crazy): {positions=DFR I(n)B2, id=DFR I(F)2, term_vectors=DFR GB1}, locale=es-MX, timezone=America/El_Salvador
[junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=4,threads=1,free=41132400,total=462946304
[junit4] 2> NOTE: All tests run in this JVM: [TestPackedTokenAttributeImpl, TestIndexSorting]
[junit4] Completed [20/452 (1!)] on J2 in 164.56s, 48 tests, 1 error <<< FAILURES!
[...truncated 12699 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/init-core-data-001
[junit4] 2> 1913996 INFO (SUITE-TestReplicationHandler-seed#[829C4BD9B8CDAE69]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 1913998 INFO (SUITE-TestReplicationHandler-seed#[829C4BD9B8CDAE69]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 1913999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestReplicateAfterStartupWithNoActivity
[junit4] 2> 1913999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1
[junit4] 2> 1914002 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1914003 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@50dc0934{/solr,null,AVAILABLE}
[junit4] 2> 1914004 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4f3f5a93{HTTP/1.1,[http/1.1]}{127.0.0.1:45220}
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server Started @1916709ms
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=45220}
[junit4] 2> 1914005 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-08T12:38:22.244Z
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/solr.xml
[junit4] 2> 1914010 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1914028 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/.
[junit4] 2> 1914028 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1914036 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 1914041 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1914043 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1914044 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/./collection1
[junit4] 2> 1914044 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1914045 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@33d8b92a
[junit4] 2> 1914097 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1914097 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1914097 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@5de32b1b
[junit4] 2> 1914098 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@c03f260[collection1] main]
[junit4] 2> 1914098 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1/conf
[junit4] 2> 1914098 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1914098 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1914099 INFO (searcherExecutor-5981-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@c03f260[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1914620 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/collection1
[junit4] 2> 1914622 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1914623 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@43362856{/solr,null,AVAILABLE}
[junit4] 2> 1914623 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1cf3e1f9{HTTP/1.1,[http/1.1]}{127.0.0.1:51656}
[junit4] 2> 1914623 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server Started @1917328ms
[junit4] 2> 1914623 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=51656}
[junit4] 2> 1914624 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-08T12:38:22.863Z
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/solr.xml
[junit4] 2> 1914629 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1914646 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/.
[junit4] 2> 1914646 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1914653 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 1914659 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1914660 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1914661 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/./collection1
[junit4] 2> 1914662 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/./collection1/data/]
[junit4] 2> 1914662 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@520880e8
[junit4] 2> 1914688 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1914688 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1914688 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@43ddd5a9
[junit4] 2> 1914689 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7a267329[collection1] main]
[junit4] 2> 1914689 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/collection1/conf
[junit4] 2> 1914691 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 1914691 INFO (searcherExecutor-5991-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7a267329[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1914845 INFO (qtp58319730-17378) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 1914845 INFO (indexFetcher-5995-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 1914845 INFO (indexFetcher-5995-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 1914846 INFO (indexFetcher-5995-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1914846 INFO (indexFetcher-5995-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 1915167 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1cf3e1f9{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1915167 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1451848266
[junit4] 2> 1915167 INFO (coreCloseExecutor-5996-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5529075e
[junit4] 2> 1915169 INFO (coreCloseExecutor-5996-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1915170 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1915170 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@43362856{/solr,null,UNAVAILABLE}
[junit4] 2> 1915171 INFO (qtp58319730-17382) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1915171 INFO (qtp58319730-17382) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 0
[junit4] 2> 1915173 INFO (qtp58319730-17375) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1915173 INFO (qtp58319730-17375) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5a54662b
[junit4] 2> 1915174 INFO (qtp58319730-17375) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@25295475[collection1] main]
[junit4] 2> 1915174 INFO (qtp58319730-17375) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1915174 INFO (searcherExecutor-5981-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@25295475[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1915174 INFO (qtp58319730-17375) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 1
[junit4] 2> 1915175 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@4f3f5a93{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1915175 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=22544708
[junit4] 2> 1915176 INFO (coreCloseExecutor-5998-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7389003
[junit4] 2> 1915177 INFO (coreCloseExecutor-5998-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1915177 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1915177 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@50dc0934{/solr,null,UNAVAILABLE}
[junit4] 2> 1915178 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1915179 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@208073ba{/solr,null,AVAILABLE}
[junit4] 2> 1915179 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@545cd856{HTTP/1.1,[http/1.1]}{127.0.0.1:35478}
[junit4] 2> 1915179 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server Started @1917884ms
[junit4] 2> 1915179 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=35478}
[junit4] 2> 1915180 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-08T12:38:23.419Z
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/solr.xml
[junit4] 2> 1915185 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1915212 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/.
[junit4] 2> 1915213 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1915219 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 1915225 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1915227 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1915228 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/./collection1
[junit4] 2> 1915229 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1915230 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=1.7880859375, floorSegmentMB=1.1396484375, forceMergeDeletesPctAllowed=22.69448066501961, segmentsPerTier=14.0, maxCFSSegmentSizeMB=0.62890625, noCFSRatio=0.0
[junit4] 2> 1915260 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1915260 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1915260 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=28, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8693303321743608]
[junit4] 2> 1915261 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5264ef7a[collection1] main]
[junit4] 2> 1915261 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1/conf
[junit4] 2> 1915261 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml
[junit4] 2> 1915261 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1915261 INFO (searcherExecutor-6006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5264ef7a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1915770 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0]} 0 0
[junit4] 2> 1915771 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0
[junit4] 2> 1915773 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 0
[junit4] 2> 1915774 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 1915776 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 1915777 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5]} 0 0
[junit4] 2> 1915779 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[6]} 0 0
[junit4] 2> 1915780 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7]} 0 0
[junit4] 2> 1915781 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8]} 0 0
[junit4] 2> 1915783 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[9]} 0 0
[junit4] 2> 1915784 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[10]} 0 0
[junit4] 2> 1915786 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[11]} 0 0
[junit4] 2> 1915787 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[12]} 0 0
[junit4] 2> 1915789 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13]} 0 0
[junit4] 2> 1915790 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[14]} 0 0
[junit4] 2> 1915792 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[15]} 0 0
[junit4] 2> 1915793 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16]} 0 0
[junit4] 2> 1915795 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17]} 0 0
[junit4] 2> 1915796 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[18]} 0 0
[junit4] 2> 1915798 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19]} 0 0
[junit4] 2> 1915800 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[20]} 0 0
[junit4] 2> 1915801 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[21]} 0 0
[junit4] 2> 1915803 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[22]} 0 0
[junit4] 2> 1915804 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[23]} 0 0
[junit4] 2> 1915806 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[24]} 0 0
[junit4] 2> 1915807 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[25]} 0 0
[junit4] 2> 1915809 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[26]} 0 0
[junit4] 2> 1915810 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27]} 0 0
[junit4] 2> 1915811 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[28]} 0 0
[junit4] 2> 1915813 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29]} 0 0
[junit4] 2> 1915814 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[30]} 0 0
[junit4] 2> 1915816 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31]} 0 0
[junit4] 2> 1915818 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[32]} 0 0
[junit4] 2> 1915819 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[33]} 0 0
[junit4] 2> 1915821 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[34]} 0 0
[junit4] 2> 1915822 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[35]} 0 0
[junit4] 2> 1915824 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[36]} 0 0
[junit4] 2> 1915825 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[37]} 0 0
[junit4] 2> 1915827 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[38]} 0 0
[junit4] 2> 1915828 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[39]} 0 0
[junit4] 2> 1915830 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[40]} 0 0
[junit4] 2> 1915831 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[41]} 0 0
[junit4] 2> 1915833 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[42]} 0 0
[junit4] 2> 1915834 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43]} 0 0
[junit4] 2> 1915836 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[44]} 0 0
[junit4] 2> 1915837 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[45]} 0 0
[junit4] 2> 1915839 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[46]} 0 0
[junit4] 2> 1915841 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[47]} 0 0
[junit4] 2> 1915842 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[48]} 0 0
[junit4] 2> 1915844 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[49]} 0 0
[junit4] 2> 1915845 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[50]} 0 0
[junit4] 2> 1915847 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[51]} 0 0
[junit4] 2> 1915849 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[52]} 0 0
[junit4] 2> 1915850 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[53]} 0 0
[junit4] 2> 1915852 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[54]} 0 0
[junit4] 2> 1915853 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[55]} 0 0
[junit4] 2> 1915855 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[56]} 0 0
[junit4] 2> 1915857 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[57]} 0 0
[junit4] 2> 1915858 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[58]} 0 0
[junit4] 2> 1915860 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[59]} 0 0
[junit4] 2> 1915861 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[60]} 0 0
[junit4] 2> 1915863 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[61]} 0 0
[junit4] 2> 1915864 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[62]} 0 0
[junit4] 2> 1915866 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[63]} 0 0
[junit4] 2> 1915867 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[64]} 0 0
[junit4] 2> 1915869 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[65]} 0 0
[junit4] 2> 1915871 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[66]} 0 0
[junit4] 2> 1915872 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[67]} 0 0
[junit4] 2> 1915874 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[68]} 0 0
[junit4] 2> 1915875 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[69]} 0 0
[junit4] 2> 1915877 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[70]} 0 0
[junit4] 2> 1915878 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[71]} 0 0
[junit4] 2> 1915880 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[72]} 0 0
[junit4] 2> 1915881 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[73]} 0 0
[junit4] 2> 1915882 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[74]} 0 0
[junit4] 2> 1915884 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[75]} 0 0
[junit4] 2> 1915885 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[76]} 0 0
[junit4] 2> 1915887 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[77]} 0 0
[junit4] 2> 1915888 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[78]} 0 0
[junit4] 2> 1915889 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[79]} 0 0
[junit4] 2> 1915891 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[80]} 0 0
[junit4] 2> 1915892 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[81]} 0 0
[junit4] 2> 1915894 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[82]} 0 0
[junit4] 2> 1915895 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[83]} 0 0
[junit4] 2> 1915896 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[84]} 0 0
[junit4] 2> 1915898 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[85]} 0 0
[junit4] 2> 1915899 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[86]} 0 0
[junit4] 2> 1915900 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[87]} 0 0
[junit4] 2> 1915902 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[88]} 0 0
[junit4] 2> 1915903 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[89]} 0 0
[junit4] 2> 1915905 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[90]} 0 0
[junit4] 2> 1915906 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[91]} 0 0
[junit4] 2> 1915908 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[92]} 0 0
[junit4] 2> 1915909 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[93]} 0 0
[junit4] 2> 1915910 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[94]} 0 0
[junit4] 2> 1915912 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[95]} 0 0
[junit4] 2> 1915913 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[96]} 0 0
[junit4] 2> 1915915 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[97]} 0 0
[junit4] 2> 1915916 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[98]} 0 0
[junit4] 2> 1915918 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[99]} 0 0
[junit4] 2> 1915919 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[100]} 0 0
[junit4] 2> 1915920 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[101]} 0 0
[junit4] 2> 1915922 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[102]} 0 0
[junit4] 2> 1915923 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[103]} 0 0
[junit4] 2> 1915925 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[104]} 0 0
[junit4] 2> 1915926 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[105]} 0 0
[junit4] 2> 1915927 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[106]} 0 0
[junit4] 2> 1915929 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[107]} 0 0
[junit4] 2> 1915930 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[108]} 0 0
[junit4] 2> 1915932 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[109]} 0 0
[junit4] 2> 1915933 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[110]} 0 0
[junit4] 2> 1915935 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[111]} 0 0
[junit4] 2> 1915936 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[112]} 0 0
[junit4] 2> 1915937 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[113]} 0 0
[junit4] 2> 1915939 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[114]} 0 0
[junit4] 2> 1915940 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[115]} 0 0
[junit4] 2> 1915942 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[116]} 0 0
[junit4] 2> 1915943 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[117]} 0 0
[junit4] 2> 1915945 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[118]} 0 0
[junit4] 2> 1915946 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[119]} 0 0
[junit4] 2> 1915948 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[120]} 0 0
[junit4] 2> 1915950 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[121]} 0 0
[junit4] 2> 1915951 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[122]} 0 0
[junit4] 2> 1915953 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[123]} 0 0
[junit4] 2> 1915955 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[124]} 0 0
[junit4] 2> 1915960 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[125]} 0 4
[junit4] 2> 1915962 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[126]} 0 0
[junit4] 2> 1915963 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[127]} 0 0
[junit4] 2> 1915965 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[128]} 0 0
[junit4] 2> 1915966 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[129]} 0 0
[junit4] 2> 1915968 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[130]} 0 0
[junit4] 2> 1915969 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[131]} 0 0
[junit4] 2> 1915971 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[132]} 0 0
[junit4] 2> 1915972 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[133]} 0 0
[junit4] 2> 1915973 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[134]} 0 0
[junit4] 2> 1915975 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[135]} 0 0
[junit4] 2> 1915976 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[136]} 0 0
[junit4] 2> 1915978 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[137]} 0 0
[junit4] 2> 1915979 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[138]} 0 0
[junit4] 2> 1915981 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[139]} 0 0
[junit4] 2> 1915982 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[140]} 0 0
[junit4] 2> 1915983 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[141]} 0 0
[junit4] 2> 1915985 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[142]} 0 0
[junit4] 2> 1915986 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[143]} 0 0
[junit4] 2> 1915988 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[144]} 0 0
[junit4] 2> 1915989 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[145]} 0 0
[junit4] 2> 1915991 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[146]} 0 0
[junit4] 2> 1915992 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[147]} 0 0
[junit4] 2> 1915993 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[148]} 0 0
[junit4] 2> 1915995 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[149]} 0 0
[junit4] 2> 1915996 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[150]} 0 0
[junit4] 2> 1915998 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[151]} 0 0
[junit4] 2> 1915999 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[152]} 0 0
[junit4] 2> 1916000 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[153]} 0 0
[junit4] 2> 1916002 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[154]} 0 0
[junit4] 2> 1916003 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[155]} 0 0
[junit4] 2> 1916005 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[156]} 0 0
[junit4] 2> 1916006 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[157]} 0 0
[junit4] 2> 1916008 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[158]} 0 0
[junit4] 2> 1916009 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[159]} 0 0
[junit4] 2> 1916010 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[160]} 0 0
[junit4] 2> 1916012 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[161]} 0 0
[junit4] 2> 1916013 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[162]} 0 0
[junit4] 2> 1916015 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[163]} 0 0
[junit4] 2> 1916016 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[164]} 0 0
[junit4] 2> 1916018 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[165]} 0 0
[junit4] 2> 1916019 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[166]} 0 0
[junit4] 2> 1916021 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[167]} 0 0
[junit4] 2> 1916022 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[168]} 0 0
[junit4] 2> 1916024 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[169]} 0 0
[junit4] 2> 1916025 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[170]} 0 0
[junit4] 2> 1916027 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[171]} 0 0
[junit4] 2> 1916028 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[172]} 0 0
[junit4] 2> 1916032 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[173]} 0 0
[junit4] 2> 1916034 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[174]} 0 0
[junit4] 2> 1916035 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[175]} 0 0
[junit4] 2> 1916037 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[176]} 0 0
[junit4] 2> 1916038 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[177]} 0 0
[junit4] 2> 1916040 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[178]} 0 0
[junit4] 2> 1916041 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[179]} 0 0
[junit4] 2> 1916042 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[180]} 0 0
[junit4] 2> 1916044 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[181]} 0 0
[junit4] 2> 1916046 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[182]} 0 0
[junit4] 2> 1916047 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[183]} 0 0
[junit4] 2> 1916048 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[184]} 0 0
[junit4] 2> 1916050 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[185]} 0 0
[junit4] 2> 1916051 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[186]} 0 0
[junit4] 2> 1916053 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[187]} 0 0
[junit4] 2> 1916055 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[188]} 0 0
[junit4] 2> 1916056 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[189]} 0 0
[junit4] 2> 1916058 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[190]} 0 0
[junit4] 2> 1916059 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[191]} 0 0
[junit4] 2> 1916061 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[192]} 0 0
[junit4] 2> 1916062 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[193]} 0 0
[junit4] 2> 1916064 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[194]} 0 0
[junit4] 2> 1916065 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[195]} 0 0
[junit4] 2> 1916066 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[196]} 0 0
[junit4] 2> 1916068 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[197]} 0 0
[junit4] 2> 1916069 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[198]} 0 0
[junit4] 2> 1916071 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[199]} 0 0
[junit4] 2> 1916072 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[200]} 0 0
[junit4] 2> 1916074 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[201]} 0 0
[junit4] 2> 1916075 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[202]} 0 0
[junit4] 2> 1916076 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[203]} 0 0
[junit4] 2> 1916078 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[204]} 0 0
[junit4] 2> 1916079 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[205]} 0 0
[junit4] 2> 1916081 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[206]} 0 0
[junit4] 2> 1916082 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[207]} 0 0
[junit4] 2> 1916084 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[208]} 0 0
[junit4] 2> 1916085 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[209]} 0 0
[junit4] 2> 1916086 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[210]} 0 0
[junit4] 2> 1916088 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[211]} 0 0
[junit4] 2> 1916089 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[212]} 0 0
[junit4] 2> 1916091 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[213]} 0 0
[junit4] 2> 1916092 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[214]} 0 0
[junit4] 2> 1916093 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[215]} 0 0
[junit4] 2> 1916095 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[216]} 0 0
[junit4] 2> 1916096 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[217]} 0 0
[junit4] 2> 1916098 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[218]} 0 0
[junit4] 2> 1916099 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[219]} 0 0
[junit4] 2> 1916101 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[220]} 0 0
[junit4] 2> 1916102 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[221]} 0 0
[junit4] 2> 1916105 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[222]} 0 0
[junit4] 2> 1916106 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[223]} 0 0
[junit4] 2> 1916107 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[224]} 0 0
[junit4] 2> 1916109 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={
[...truncated too long message...]
path=/update params={wt=javabin&version=2}{add=[554]} 0 0
[junit4] 2> 2557424 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2557424 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@3b566bad
[junit4] 2> 2557434 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@68c4a09c[collection1] main]
[junit4] 2> 2557434 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2557434 INFO (searcherExecutor-6879-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@68c4a09c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(6.5.0):c1) Uninverting(_1(6.5.0):c1) Uninverting(_3(6.5.0):c1) Uninverting(_4(6.5.0):c1)))}
[junit4] 2> 2557434 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 10
[junit4] 2> 2557438 INFO (qtp1239514442-19189) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[555]} 0 0
[junit4] 2> 2557439 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2557439 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@3b566bad
[junit4] 2> 2557445 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f390aa2[collection1] main]
[junit4] 2> 2557445 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2557445 INFO (searcherExecutor-6879-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5f390aa2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(6.5.0):c1) Uninverting(_1(6.5.0):c1) Uninverting(_3(6.5.0):c1) Uninverting(_4(6.5.0):c1) Uninverting(_5(6.5.0):c1)))}
[junit4] 2> 2557445 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 6
[junit4] 2> 2557447 INFO (qtp1239514442-19190) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=id:555&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 2557447 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 2557448 INFO (qtp1021027092-19171) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={command=enablereplication} status=0 QTime=0
[junit4] 2> 2557450 INFO (qtp1239514442-19188) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={command=fetchindex} status=0 QTime=1
[junit4] 2> 2557450 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.SolrTestCaseJ4 ###Ending doTestReplicateAfterWrite2Slave
[junit4] 2> 2557451 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@70c399ff{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 2557451 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1969462354
[junit4] 2> 2557451 ERROR (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master at: http://127.0.0.1:47377/solr/collection1 is not available. Index fetch failed. Exception: Server refused connection at: http://127.0.0.1:47377/solr/collection1
[junit4] 2> 2557452 INFO (coreCloseExecutor-6884-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5eeca976
[junit4] 2> 2557453 INFO (coreCloseExecutor-6884-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 2557454 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2557454 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@792e465e{/solr,null,UNAVAILABLE}
[junit4] 2> 2557455 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@10522d71{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 2557455 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1747387634
[junit4] 2> 2557455 INFO (coreCloseExecutor-6886-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@108f0157
[junit4] 2> 2557458 INFO (coreCloseExecutor-6886-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 2557459 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2557459 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5f48be1b{/solr,null,UNAVAILABLE}
[junit4] 2> 2557460 INFO (SUITE-TestReplicationHandler-seed#[829C4BD9B8CDAE69]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=sq-AL, timezone=Africa/Nairobi
[junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=4,threads=1,free=197212072,total=533200896
[junit4] 2> NOTE: All tests run in this JVM: [HdfsNNFailoverTest, TestDefaultStatsCache, TestConfigReload, HttpPartitionTest, SolrIndexMetricsTest, TestExtendedDismaxParser, TestCustomSort, CurrencyFieldXmlFileTest, CoreAdminRequestStatusTest, TestJsonFacetRefinement, SuggestComponentContextFilterQueryTest, EnumFieldTest, TestSolrCLIRunExample, MetricsHandlerTest, HLLUtilTest, TermVectorComponentDistributedTest, HardAutoCommitTest, TestConfig, TimeZoneUtilsTest, TestWriterPerf, PrimUtilsTest, ConcurrentDeleteAndCreateCollectionTest, BasicDistributedZk2Test, DeleteLastCustomShardedReplicaTest, CreateCollectionCleanupTest, SolrCloudExampleTest, SolrSlf4jReporterTest, FieldAnalysisRequestHandlerTest, CollectionTooManyReplicasTest, GraphQueryTest, TestSolrQueryParserResource, TestCoreDiscovery, TestSystemCollAutoCreate, TestHdfsCloudBackupRestore, DocValuesMultiTest, TestClassNameShortening, TestReversedWildcardFilterFactory, TestCollectionAPI, TestMaxScoreQueryParser, OverseerModifyCollectionTest, TestOverriddenPrefixQueryForCustomFieldType, ClassificationUpdateProcessorTest, BlockJoinFacetDistribTest, StatsReloadRaceTest, TestUtils, TestHdfsUpdateLog, BinaryUpdateRequestHandlerTest, UnloadDistributedZkTest, TestCollapseQParserPlugin, FieldMutatingUpdateProcessorTest, BlockDirectoryTest, TestJmxMonitoredMap, TestLFUCache, TestFieldCacheReopen, TestAnalyzedSuggestions, JSONWriterTest, TestLMJelinekMercerSimilarityFactory, DistribDocExpirationUpdateProcessorTest, TestExactStatsCache, TestPerFieldSimilarityClassic, TestFreeTextSuggestions, RequestHandlersTest, TestDynamicFieldCollectionResource, TestManagedResourceStorage, TestAnalyzeInfixSuggestions, LeaderElectionTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, MinimalSchemaTest, QueryParsingTest, SuggesterTSTTest, SharedFSAutoReplicaFailoverUtilsTest, TestSolrFieldCacheMBean, TestIndexingPerformance, TestSchemaNameResource, TestSort, PingRequestHandlerTest, TestMacros, TestSchemaVersionResource, DirectUpdateHandlerTest, TestConfigsApi, TestGeoJSONResponseWriter, TestManagedSchema, ShowFileRequestHandlerTest, TestOrdValues, AnalyticsQueryTest, RestartWhileUpdatingTest, DeleteShardTest, TestXIncludeConfig, CdcrUpdateLogTest, ExitableDirectoryReaderTest, HdfsTlogReplayBufferedWhileIndexingTest, DistributedFacetPivotLongTailTest, TestSolrCloudWithKerberosAlt, TestPhraseSuggestions, HdfsChaosMonkeyNothingIsSafeTest, OverseerTest, ReplicaListTransformerTest, TestPKIAuthenticationPlugin, TestSubQueryTransformerCrossCore, SaslZkACLProviderTest, HttpSolrCallGetCoreTest, ActionThrottleTest, ChangedSchemaMergeTest, TestSolrJ, CdcrVersionReplicationTest, TestStressReorder, TestLegacyFieldCache, TestRecovery, TestShortCircuitedRequests, TestFieldResource, TestReqParamsAPI, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, TestReplicationHandler]
[junit4] Completed [503/697 (1!)] on J2 in 643.48s, 16 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 63302 lines...]
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still Unstable
Posted by Uwe Schindler <uw...@thetaphi.de>.
Thanks Robert for reminding me. Because there was a similar discussion about this in the Jenkins Mac Slave. In fact the issue was not caused by this limit as Jenkins Slave already started with 2048 limit.
Please don't raise the hardcoded test limit. It will likely break on Jenkins anyways. Better have a hard and low limit in test framework instead of hard to reproduce failures in Jenkins.
Uwe
Am 8. März 2017 17:50:04 MEZ schrieb Robert Muir <rc...@gmail.com>:
>If you don't like the limit for your specific test: use
>@SuppressFileSystems annotation to suppress it.
>
>But it is really insane for a unit test to use so many index files,
>and it is important to reproduce such bugs when they do happen.
>
>On Wed, Mar 8, 2017 at 11:46 AM, Chris Hostetter
><ho...@fucit.org> wrote:
>>
>> The exception is being thrown by
>org.apache.lucene.mockfile.HandleLimitFS,
>> so the OS level utlimit isn't relevant (as long as it's greter then
>2048,
>> hardcoded in TestRuleTemporaryFilesCleanup)
>>
>> With the test creating 2 diff indexes, that means each index index
>gets an
>> effective max open files limit of ~1024 files ... and with
>> RandomSimilarity it might be leaving a lot of small segments on
>"disk" for
>> both of those indexes -- which will have at least 100,000 docs in
>each
>> because this is a nightly run....
>>
>> I haven't tested this (my co is currently dirty and i'm in the middle
>of
>> something) but i suspect the seed will reproduce anywhere.
>>
>> See also SOLR-10234 where i recently pointed out similar concerns
>about
>> TestRuleTemporaryFilesCleanup's fixed limit of 2048 for the entire
>JVM,
>> even when the JVM itself is trying to simulate multiple diff indexes
>(or
>> completley distint nodes in the solr cloud test case).
>>
>>
>>
>> : Date: Wed, 8 Mar 2017 11:29:45 -0500
>> : From: Steve Rowe <sa...@gmail.com>
>> : Reply-To: dev@lucene.apache.org
>> : To: dev@lucene.apache.org
>> : Subject: Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 -
>Still
>> : Unstable
>> :
>> :
>> : > On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server
><je...@builds.apache.org> wrote:
>> : >
>> : > Build:
>https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
>> : >
>> : > 2 tests failed.
>> : > FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
>> : >
>> : > Error Message:
>> : >
>/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim:
>Too many open files
>> : >
>> : > Stack Trace:
>> : > java.nio.file.FileSystemException:
>/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim:
>Too many open files
>> :
>> : I logged in as the jenkins user on lucene1-us-west.apache.org (the
>‘lucene' jenkins slave), and ‘ulimit -aHS’ says (in part):
>> :
>> : open files (-n) 1048576
>> :
>> : I think this is the maximum value.
>> :
>> : Not sure what can be done here?
>> :
>> : --
>> : Steve
>> : www.lucidworks.com
>> :
>> :
>> :
>---------------------------------------------------------------------
>> : To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> : For additional commands, e-mail: dev-help@lucene.apache.org
>> :
>> :
>>
>> -Hoss
>> http://www.lucidworks.com/
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> For additional commands, e-mail: dev-help@lucene.apache.org
>
>---------------------------------------------------------------------
>To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>For additional commands, e-mail: dev-help@lucene.apache.org
--
Uwe Schindler
Achterdiek 19, 28357 Bremen
https://www.thetaphi.de
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still Unstable
Posted by Robert Muir <rc...@gmail.com>.
On Wed, Mar 8, 2017 at 12:04 PM, Chris Hostetter
<ho...@fucit.org> wrote:
>
> : If you don't like the limit for your specific test: use
> : @SuppressFileSystems annotation to suppress it.
> :
> : But it is really insane for a unit test to use so many index files,
> : and it is important to reproduce such bugs when they do happen.
>
> i'm not disagreeing with the value of HandleLimitFS.
>
> I'm saying that in tests like TestIndexSorting.testRandom3 -- where the
> point is to create 2 distinct indexes and compare some things about them
> -- having a single limit for the entire JVM isn't as useful as if there
> was an easy way to just limit the number of open files per index (or for
> the test to declare "treat these indexes as if they were on distinct
> filesystems").
This isn't how operating systems work though. They don't care about
how many indexes or filesystems you have, its a file handle limit for
the process (entire JVM). So this simply reflects that.
2048 is already far too much: on my mac the default limit is only 256.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
Unstable
Posted by Chris Hostetter <ho...@fucit.org>.
: If you don't like the limit for your specific test: use
: @SuppressFileSystems annotation to suppress it.
:
: But it is really insane for a unit test to use so many index files,
: and it is important to reproduce such bugs when they do happen.
i'm not disagreeing with the value of HandleLimitFS.
I'm saying that in tests like TestIndexSorting.testRandom3 -- where the
point is to create 2 distinct indexes and compare some things about them
-- having a single limit for the entire JVM isn't as useful as if there
was an easy way to just limit the number of open files per index (or for
the test to declare "treat these indexes as if they were on distinct
filesystems").
a knob/hook like this would also be useful in distributed Solr tests, to
say "we want this simulated solr nodeA to act as if it has it's own
filesystem independent from nodeB's filesystem" -- that way we can still
have the benefit of sanity checks that code isn't using too many files
(per *NODE*) and we wouldn't need to use a sledghammer of completely
supressing HandleLimitFS in tests.
Perhaps, in an ideal world, when tests call
LuceneTestCase.createTempDir(...) they could (optionally) pass in some
identifier for what (conceptual/virtual) filesystem they want to use -- so
they default is to assume all temp dirs created in a test come from the
same (mock) filesystem using HandleLimitFS with a (shared) max ... but
tests like TestIndexSorting.testRandom3 could request that the 2 distinct
indexes live ontheir own filesystems; and things like Solr's cloud test
scaffolding could request that each node get their own "virtual"
filesystems (with their own limits)
?
-Hoss
http://www.lucidworks.com/
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still Unstable
Posted by Robert Muir <rc...@gmail.com>.
If you don't like the limit for your specific test: use
@SuppressFileSystems annotation to suppress it.
But it is really insane for a unit test to use so many index files,
and it is important to reproduce such bugs when they do happen.
On Wed, Mar 8, 2017 at 11:46 AM, Chris Hostetter
<ho...@fucit.org> wrote:
>
> The exception is being thrown by org.apache.lucene.mockfile.HandleLimitFS,
> so the OS level utlimit isn't relevant (as long as it's greter then 2048,
> hardcoded in TestRuleTemporaryFilesCleanup)
>
> With the test creating 2 diff indexes, that means each index index gets an
> effective max open files limit of ~1024 files ... and with
> RandomSimilarity it might be leaving a lot of small segments on "disk" for
> both of those indexes -- which will have at least 100,000 docs in each
> because this is a nightly run....
>
> I haven't tested this (my co is currently dirty and i'm in the middle of
> something) but i suspect the seed will reproduce anywhere.
>
> See also SOLR-10234 where i recently pointed out similar concerns about
> TestRuleTemporaryFilesCleanup's fixed limit of 2048 for the entire JVM,
> even when the JVM itself is trying to simulate multiple diff indexes (or
> completley distint nodes in the solr cloud test case).
>
>
>
> : Date: Wed, 8 Mar 2017 11:29:45 -0500
> : From: Steve Rowe <sa...@gmail.com>
> : Reply-To: dev@lucene.apache.org
> : To: dev@lucene.apache.org
> : Subject: Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
> : Unstable
> :
> :
> : > On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server <je...@builds.apache.org> wrote:
> : >
> : > Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
> : >
> : > 2 tests failed.
> : > FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
> : >
> : > Error Message:
> : > /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
> : >
> : > Stack Trace:
> : > java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
> :
> : I logged in as the jenkins user on lucene1-us-west.apache.org (the ‘lucene' jenkins slave), and ‘ulimit -aHS’ says (in part):
> :
> : open files (-n) 1048576
> :
> : I think this is the maximum value.
> :
> : Not sure what can be done here?
> :
> : --
> : Steve
> : www.lucidworks.com
> :
> :
> : ---------------------------------------------------------------------
> : To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> : For additional commands, e-mail: dev-help@lucene.apache.org
> :
> :
>
> -Hoss
> http://www.lucidworks.com/
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
Unstable
Posted by Chris Hostetter <ho...@fucit.org>.
The exception is being thrown by org.apache.lucene.mockfile.HandleLimitFS,
so the OS level utlimit isn't relevant (as long as it's greter then 2048,
hardcoded in TestRuleTemporaryFilesCleanup)
With the test creating 2 diff indexes, that means each index index gets an
effective max open files limit of ~1024 files ... and with
RandomSimilarity it might be leaving a lot of small segments on "disk" for
both of those indexes -- which will have at least 100,000 docs in each
because this is a nightly run....
I haven't tested this (my co is currently dirty and i'm in the middle of
something) but i suspect the seed will reproduce anywhere.
See also SOLR-10234 where i recently pointed out similar concerns about
TestRuleTemporaryFilesCleanup's fixed limit of 2048 for the entire JVM,
even when the JVM itself is trying to simulate multiple diff indexes (or
completley distint nodes in the solr cloud test case).
: Date: Wed, 8 Mar 2017 11:29:45 -0500
: From: Steve Rowe <sa...@gmail.com>
: Reply-To: dev@lucene.apache.org
: To: dev@lucene.apache.org
: Subject: Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
: Unstable
:
:
: > On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server <je...@builds.apache.org> wrote:
: >
: > Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
: >
: > 2 tests failed.
: > FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
: >
: > Error Message:
: > /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
: >
: > Stack Trace:
: > java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
:
: I logged in as the jenkins user on lucene1-us-west.apache.org (the lucene' jenkins slave), and ulimit -aHS says (in part):
:
: open files (-n) 1048576
:
: I think this is the maximum value.
:
: Not sure what can be done here?
:
: --
: Steve
: www.lucidworks.com
:
:
: ---------------------------------------------------------------------
: To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
: For additional commands, e-mail: dev-help@lucene.apache.org
:
:
-Hoss
http://www.lucidworks.com/
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still Unstable
Posted by Robert Muir <rc...@gmail.com>.
The exception is not from the operating system: it is from the test framework.
https://github.com/apache/lucene-solr/blob/master/lucene/test-framework/src/java/org/apache/lucene/mockfile/HandleLimitFS.java#L48
This is currently limited to 2048. We should not increase it: the idea
is to catch buggy/crazy tests just like this one.
https://github.com/apache/lucene-solr/blob/master/lucene/test-framework/src/java/org/apache/lucene/util/TestRuleTemporaryFilesCleanup.java#L117-L119
On Wed, Mar 8, 2017 at 11:29 AM, Steve Rowe <sa...@gmail.com> wrote:
>
>> On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server <je...@builds.apache.org> wrote:
>>
>> Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
>>
>> 2 tests failed.
>> FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
>>
>> Error Message:
>> /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
>>
>> Stack Trace:
>> java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
>
> I logged in as the jenkins user on lucene1-us-west.apache.org (the ‘lucene' jenkins slave), and ‘ulimit -aHS’ says (in part):
>
> open files (-n) 1048576
>
> I think this is the maximum value.
>
> Not sure what can be done here?
>
> --
> Steve
> www.lucidworks.com
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
Unstable
Posted by Steve Rowe <sa...@gmail.com>.
> On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server <je...@builds.apache.org> wrote:
>
> Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
>
> 2 tests failed.
> FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
>
> Error Message:
> /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
>
> Stack Trace:
> java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
I logged in as the jenkins user on lucene1-us-west.apache.org (the ‘lucene' jenkins slave), and ‘ulimit -aHS’ says (in part):
open files (-n) 1048576
I think this is the maximum value.
Not sure what can be done here?
--
Steve
www.lucidworks.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org