You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2016/02/16 21:23:48 UTC
[JENKINS] Lucene-Solr-5.x-Windows (32bit/jdk1.7.0_80) - Build #
5490 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-Windows/5490/
Java: 32bit/jdk1.7.0_80 -server -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.lucene.store.TestNativeFSLockFactory.testStressLocks
Error Message:
IndexWriter hit unexpected exceptions
Stack Trace:
java.lang.AssertionError: IndexWriter hit unexpected exceptions
at __randomizedtesting.SeedInfo.seed([9BA6F0917BCE9B90:C597BE6C676253F6]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.lucene.store.BaseLockFactoryTestCase.testStressLocks(BaseLockFactoryTestCase.java:174)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
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:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
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:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 1513 lines...]
[junit4] Suite: org.apache.lucene.store.TestNativeFSLockFactory
[junit4] 1> Stress Test Index Writer: creation hit unexpected exception: java.io.FileNotFoundException: segments_p in dir=MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653
[junit4] 1> java.io.FileNotFoundException: segments_p in dir=MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653
[junit4] 1> at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:640)
[junit4] 1> at org.apache.lucene.store.Directory.openChecksumInput(Directory.java:109)
[junit4] 1> at org.apache.lucene.store.MockDirectoryWrapper.openChecksumInput(MockDirectoryWrapper.java:1009)
[junit4] 1> at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:294)
[junit4] 1> at org.apache.lucene.index.IndexFileDeleter.<init>(IndexFileDeleter.java:171)
[junit4] 1> at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:949)
[junit4] 1> at org.apache.lucene.store.BaseLockFactoryTestCase$WriterThread.run(BaseLockFactoryTestCase.java:229)
[junit4] 1>
[junit4] 1> TEST: WriterThread iter=0
[junit4] 1> IFD 1 [2016-02-16T20:22:30.901Z; Thread-1221]: init: current segments file is "segments_1"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1d38cd
[junit4] 1> IFD 1 [2016-02-16T20:22:30.901Z; Thread-1221]: init: load commit "segments_1"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.902Z; Thread-1221]: now checkpoint "_0(5.6.0):c1" [1 segments ; isCommit = false]
[junit4] 1> IFD 1 [2016-02-16T20:22:30.902Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IW 1 [2016-02-16T20:22:30.903Z; Thread-1221]: init: create=false
[junit4] 1> IW 1 [2016-02-16T20:22:30.903Z; Thread-1221]:
[junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
[junit4] 1> index=_0(5.6.0):c1
[junit4] 1> version=5.6.0
[junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
[junit4] 1> ramBufferSizeMB=16.0
[junit4] 1> maxBufferedDocs=-1
[junit4] 1> maxBufferedDeleteTerms=-1
[junit4] 1> mergedSegmentWarmer=null
[junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
[junit4] 1> commit=null
[junit4] 1> openMode=APPEND
[junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
[junit4] 1> default WRITE_LOCK_TIMEOUT=0
[junit4] 1> writeLockTimeout=0
[junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
[junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
[junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@1b4a0ca
[junit4] 1> readerPooling=false
[junit4] 1> perThreadHardLimitMB=1945
[junit4] 1> useCompoundFile=true
[junit4] 1> commitOnClose=true
[junit4] 1> writer=org.apache.lucene.index.IndexWriter@1a832c0
[junit4] 1>
[junit4] 1> IW 1 [2016-02-16T20:22:30.903Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 1> IW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: now flush at close
[junit4] 1> IW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: start flush: applyAllDeletes=true
[junit4] 1> IW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: index before flush _0(5.6.0):c1
[junit4] 1> DW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: startFullFlush
[junit4] 1> DW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 1> DWFC 1 [2016-02-16T20:22:30.906Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
[junit4] 1> DWPT 1 [2016-02-16T20:22:30.906Z; Thread-1221]: flush postings as segment _1 numDocs=1
[junit4] 1> IW 1 [2016-02-16T20:22:30.907Z; Thread-1221]: 1 msec to write norms
[junit4] 1> IW 1 [2016-02-16T20:22:30.907Z; Thread-1221]: 0 msec to write docValues
[junit4] 1> IW 1 [2016-02-16T20:22:30.91Z; Thread-1221]: 2 msec to finish stored fields
[junit4] 1> IW 1 [2016-02-16T20:22:30.916Z; Thread-1221]: 5 msec to write postings and finish vectors
[junit4] 1> IW 1 [2016-02-16T20:22:30.917Z; Thread-1221]: 1 msec to write fieldInfos
[junit4] 1> DWPT 1 [2016-02-16T20:22:30.917Z; Thread-1221]: new segment has 0 deleted docs
[junit4] 1> DWPT 1 [2016-02-16T20:22:30.917Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 1> DWPT 1 [2016-02-16T20:22:30.917Z; Thread-1221]: flushedFiles=[_1_Lucene50_0.pos, _1.fdx, _1_Lucene50_0.doc, _1.fdt, _1.fnm, _1.nvm, _1_Lucene50_0.tip, _1_Lucene50_0.tim, _1.nvd]
[junit4] 1> DWPT 1 [2016-02-16T20:22:30.917Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> DWPT 1 [2016-02-16T20:22:30.918Z; Thread-1221]: flushed: segment=_1 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
[junit4] 1> IW 1 [2016-02-16T20:22:30.919Z; Thread-1221]: create compound file
[junit4] 1> DW 1 [2016-02-16T20:22:30.923Z; Thread-1221]: publishFlushedSegment seg-private updates=null
[junit4] 1> IW 1 [2016-02-16T20:22:30.924Z; Thread-1221]: publishFlushedSegment
[junit4] 1> IW 1 [2016-02-16T20:22:30.924Z; Thread-1221]: publish sets newSegment delGen=1 seg=_1(5.6.0):c1
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1" [2 segments ; isCommit = false]
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> DW 1 [2016-02-16T20:22:30.924Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1_Lucene50_0.pos"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.fdx"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1_Lucene50_0.doc"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.fdt"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.fnm"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.nvm"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1_Lucene50_0.tip"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1_Lucene50_0.tim"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.nvd"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: delete "_1_Lucene50_0.pos"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: delete "_1_Lucene50_0.doc"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.925Z; Thread-1221]: delete "_1.fdx"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.925Z; Thread-1221]: delete "_1.fnm"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.925Z; Thread-1221]: delete "_1.fdt"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: delete "_1.nvm"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: unable to remove file "_1.nvm": java.io.IOException: cannot delete file: _1.nvm, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: delete "_1_Lucene50_0.tip"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: delete "_1_Lucene50_0.tim"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: delete "_1.nvd"
[junit4] 1> IW 1 [2016-02-16T20:22:30.927Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 1 [2016-02-16T20:22:30.927Z; Thread-1221]: now apply all deletes for all segments maxDoc=2
[junit4] 1> BD 1 [2016-02-16T20:22:30.927Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 1 [2016-02-16T20:22:30.927Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 1 [2016-02-16T20:22:30.927Z; Thread-1221]: prune sis=segments_1: _0(5.6.0):c1 _1(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> TMP 1 [2016-02-16T20:22:30.927Z; Thread-1221]: findMerges: 2 segments
[junit4] 1> TMP 1 [2016-02-16T20:22:30.928Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 1 [2016-02-16T20:22:30.929Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 1 [2016-02-16T20:22:30.929Z; Thread-1221]: allowedSegmentCount=1 vs count=2 (eligible count=2) tooBigCount=0
[junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
[junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: now merge
[junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1
[junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: no more merges pending; now return
[junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
[junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: now merge
[junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1
[junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: no more merges pending; now return
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: waitForMerges
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: waitForMerges done
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: commit: start
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: commit: enter lock
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: commit: now prepare
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: prepareCommit: flush
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1
[junit4] 1> DW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: startFullFlush
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: now apply all deletes for all segments maxDoc=2
[junit4] 1> BD 1 [2016-02-16T20:22:30.929Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 1 [2016-02-16T20:22:30.929Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 1 [2016-02-16T20:22:30.929Z; Thread-1221]: prune sis=segments_1: _0(5.6.0):c1 _1(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> DW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: startCommit(): start
[junit4] 1> IW 1 [2016-02-16T20:22:30.93Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 changeCount=3
[junit4] 1> IW 1 [2016-02-16T20:22:30.932Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_2"
[junit4] 1> IW 1 [2016-02-16T20:22:30.932Z; Thread-1221]: done all syncs: [_1.si, _0.cfe, _1.cfe, _0.si, _1.cfs, _0.cfs]
[junit4] 1> IW 1 [2016-02-16T20:22:30.932Z; Thread-1221]: commit: pendingCommit != null
[junit4] 1> IW 1 [2016-02-16T20:22:30.934Z; Thread-1221]: commit: done writing segments file "segments_2"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.934Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1" [2 segments ; isCommit = true]
[junit4] 1> IFD 1 [2016-02-16T20:22:30.934Z; Thread-1221]: deleteCommits: now decRef commit "segments_1"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.934Z; Thread-1221]: delete "segments_1"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.936Z; Thread-1221]: delete "_1.nvm"
[junit4] 1> IFD 1 [2016-02-16T20:22:30.936Z; Thread-1221]: unable to remove file "_1.nvm": java.io.IOException: cannot delete file: _1.nvm, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 1 [2016-02-16T20:22:30.936Z; Thread-1221]: 2 msec to checkpoint
[junit4] 1> IFD 1 [2016-02-16T20:22:30.936Z; Thread-1221]: delete "_1.nvm"
[junit4] 1> IW 1 [2016-02-16T20:22:30.936Z; Thread-1221]: commit: took 7.2 msec
[junit4] 1> IW 1 [2016-02-16T20:22:30.936Z; Thread-1221]: commit: done
[junit4] 1> IW 1 [2016-02-16T20:22:30.936Z; Thread-1221]: rollback
[junit4] 1> IW 1 [2016-02-16T20:22:30.936Z; Thread-1221]: all running merges have aborted
[junit4] 1> IW 1 [2016-02-16T20:22:30.937Z; Thread-1221]: rollback: done finish merges
[junit4] 1> DW 1 [2016-02-16T20:22:30.937Z; Thread-1221]: abort
[junit4] 1> DW 1 [2016-02-16T20:22:30.937Z; Thread-1221]: done abort success=true
[junit4] 1> IW 1 [2016-02-16T20:22:30.937Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1
[junit4] 1> IFD 1 [2016-02-16T20:22:30.937Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1" [2 segments ; isCommit = false]
[junit4] 1> IFD 1 [2016-02-16T20:22:30.937Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1>
[junit4] 1> TEST: WriterThread iter=1
[junit4] 1> IFD 2 [2016-02-16T20:22:30.94Z; Thread-1221]: init: current segments file is "segments_2"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@56e48d
[junit4] 1> IFD 2 [2016-02-16T20:22:30.94Z; Thread-1221]: init: load commit "segments_2"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.943Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1" [2 segments ; isCommit = false]
[junit4] 1> IFD 2 [2016-02-16T20:22:30.943Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IW 2 [2016-02-16T20:22:30.946Z; Thread-1221]: init: create=false
[junit4] 1> IW 2 [2016-02-16T20:22:30.946Z; Thread-1221]:
[junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
[junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1
[junit4] 1> version=5.6.0
[junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
[junit4] 1> ramBufferSizeMB=16.0
[junit4] 1> maxBufferedDocs=-1
[junit4] 1> maxBufferedDeleteTerms=-1
[junit4] 1> mergedSegmentWarmer=null
[junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
[junit4] 1> commit=null
[junit4] 1> openMode=APPEND
[junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
[junit4] 1> default WRITE_LOCK_TIMEOUT=0
[junit4] 1> writeLockTimeout=0
[junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
[junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
[junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@1765c5b
[junit4] 1> readerPooling=false
[junit4] 1> perThreadHardLimitMB=1945
[junit4] 1> useCompoundFile=true
[junit4] 1> commitOnClose=true
[junit4] 1> writer=org.apache.lucene.index.IndexWriter@1a9969c
[junit4] 1>
[junit4] 1> IW 2 [2016-02-16T20:22:30.946Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 1> IW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: now flush at close
[junit4] 1> IW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: start flush: applyAllDeletes=true
[junit4] 1> IW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1
[junit4] 1> DW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: startFullFlush
[junit4] 1> DW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 1> DWFC 2 [2016-02-16T20:22:30.949Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
[junit4] 1> DWPT 2 [2016-02-16T20:22:30.949Z; Thread-1221]: flush postings as segment _2 numDocs=1
[junit4] 1> IW 2 [2016-02-16T20:22:30.951Z; Thread-1221]: 1 msec to write norms
[junit4] 1> IW 2 [2016-02-16T20:22:30.951Z; Thread-1221]: 0 msec to write docValues
[junit4] 1> IW 2 [2016-02-16T20:22:30.951Z; Thread-1221]: 0 msec to finish stored fields
[junit4] 1> IW 2 [2016-02-16T20:22:30.954Z; Thread-1221]: 3 msec to write postings and finish vectors
[junit4] 1> IW 2 [2016-02-16T20:22:30.957Z; Thread-1221]: 1 msec to write fieldInfos
[junit4] 1> DWPT 2 [2016-02-16T20:22:30.957Z; Thread-1221]: new segment has 0 deleted docs
[junit4] 1> DWPT 2 [2016-02-16T20:22:30.957Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 1> DWPT 2 [2016-02-16T20:22:30.957Z; Thread-1221]: flushedFiles=[_2_Lucene50_0.tim, _2.fdx, _2.nvm, _2_Lucene50_0.doc, _2.fdt, _2_Lucene50_0.tip, _2.fnm, _2_Lucene50_0.pos, _2.nvd]
[junit4] 1> DWPT 2 [2016-02-16T20:22:30.957Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> DWPT 2 [2016-02-16T20:22:30.958Z; Thread-1221]: flushed: segment=_2 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
[junit4] 1> IW 2 [2016-02-16T20:22:30.958Z; Thread-1221]: create compound file
[junit4] 1> DW 2 [2016-02-16T20:22:30.964Z; Thread-1221]: publishFlushedSegment seg-private updates=null
[junit4] 1> IW 2 [2016-02-16T20:22:30.964Z; Thread-1221]: publishFlushedSegment
[junit4] 1> IW 2 [2016-02-16T20:22:30.964Z; Thread-1221]: publish sets newSegment delGen=1 seg=_2(5.6.0):c1
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1" [3 segments ; isCommit = false]
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> DW 2 [2016-02-16T20:22:30.964Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2_Lucene50_0.tim"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2.fdx"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2.nvm"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2_Lucene50_0.doc"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2.fdt"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2_Lucene50_0.tip"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2.fnm"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2_Lucene50_0.pos"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: will delete new file "_2.nvd"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: delete "_2_Lucene50_0.tim"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: delete "_2.fdx"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: unable to remove file "_2.fdx": java.io.IOException: cannot delete file: _2.fdx, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: delete "_2_Lucene50_0.doc"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: unable to remove file "_2_Lucene50_0.doc": java.io.IOException: cannot delete file: _2_Lucene50_0.doc, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: delete "_2.nvm"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.966Z; Thread-1221]: delete "_2_Lucene50_0.tip"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.966Z; Thread-1221]: delete "_2.fdt"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.966Z; Thread-1221]: delete "_2.fnm"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.967Z; Thread-1221]: delete "_2_Lucene50_0.pos"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.967Z; Thread-1221]: delete "_2.nvd"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.967Z; Thread-1221]: unable to remove file "_2.nvd": java.io.IOException: cannot delete file: _2.nvd, a virus scanner has it open; Will re-try later.
[junit4] 1> IW 2 [2016-02-16T20:22:30.968Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 2 [2016-02-16T20:22:30.968Z; Thread-1221]: now apply all deletes for all segments maxDoc=3
[junit4] 1> BD 2 [2016-02-16T20:22:30.968Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 2 [2016-02-16T20:22:30.968Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 2 [2016-02-16T20:22:30.968Z; Thread-1221]: prune sis=segments_2: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> TMP 2 [2016-02-16T20:22:30.968Z; Thread-1221]: findMerges: 3 segments
[junit4] 1> TMP 2 [2016-02-16T20:22:30.969Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 2 [2016-02-16T20:22:30.969Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 2 [2016-02-16T20:22:30.969Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 2 [2016-02-16T20:22:30.969Z; Thread-1221]: allowedSegmentCount=1 vs count=3 (eligible count=3) tooBigCount=0
[junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
[junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: now merge
[junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
[junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: no more merges pending; now return
[junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
[junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: now merge
[junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
[junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: no more merges pending; now return
[junit4] 1> IW 2 [2016-02-16T20:22:30.97Z; Thread-1221]: waitForMerges
[junit4] 1> IW 2 [2016-02-16T20:22:30.97Z; Thread-1221]: waitForMerges done
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: commit: start
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: commit: enter lock
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: commit: now prepare
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: prepareCommit: flush
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
[junit4] 1> DW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: startFullFlush
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: now apply all deletes for all segments maxDoc=3
[junit4] 1> BD 2 [2016-02-16T20:22:30.971Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 2 [2016-02-16T20:22:30.971Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 2 [2016-02-16T20:22:30.971Z; Thread-1221]: prune sis=segments_2: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> DW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: startCommit(): start
[junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 changeCount=3
[junit4] 1> IW 2 [2016-02-16T20:22:30.975Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_3"
[junit4] 1> IW 2 [2016-02-16T20:22:30.976Z; Thread-1221]: done all syncs: [_2.si, _1.si, _0.cfe, _2.cfe, _2.cfs, _1.cfe, _0.si, _1.cfs, _0.cfs]
[junit4] 1> IW 2 [2016-02-16T20:22:30.976Z; Thread-1221]: commit: pendingCommit != null
[junit4] 1> IW 2 [2016-02-16T20:22:30.977Z; Thread-1221]: commit: done writing segments file "segments_3"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.977Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1" [3 segments ; isCommit = true]
[junit4] 1> IFD 2 [2016-02-16T20:22:30.977Z; Thread-1221]: deleteCommits: now decRef commit "segments_2"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.977Z; Thread-1221]: delete "segments_2"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: unable to remove file "segments_2": java.io.IOException: MockDirectoryWrapper: file "segments_2" is still open: cannot delete; Will re-try later.
[junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: failed to remove commit point "segments_2"; skipping deletion of all other pending files
[junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: delete "segments_2"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: unable to remove file "segments_2": java.io.IOException: MockDirectoryWrapper: file "segments_2" is still open: cannot delete; Will re-try later.
[junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: failed to remove commit point "segments_2"; skipping deletion of all other pending files
[junit4] 1> IW 2 [2016-02-16T20:22:30.978Z; Thread-1221]: commit: took 8.2 msec
[junit4] 1> IW 2 [2016-02-16T20:22:30.978Z; Thread-1221]: commit: done
[junit4] 1> IW 2 [2016-02-16T20:22:30.978Z; Thread-1221]: rollback
[junit4] 1> IW 2 [2016-02-16T20:22:30.978Z; Thread-1221]: all running merges have aborted
[junit4] 1> IW 2 [2016-02-16T20:22:30.979Z; Thread-1221]: rollback: done finish merges
[junit4] 1> DW 2 [2016-02-16T20:22:30.979Z; Thread-1221]: abort
[junit4] 1> DW 2 [2016-02-16T20:22:30.979Z; Thread-1221]: done abort success=true
[junit4] 1> IW 2 [2016-02-16T20:22:30.979Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
[junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1" [3 segments ; isCommit = false]
[junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: delete "segments_2"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: unable to remove file "segments_2": java.nio.file.AccessDeniedException: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001\segments_2; Will re-try later.
[junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: failed to remove commit point "segments_2"; skipping deletion of all other pending files
[junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: refresh: removing newly created unreferenced file "segments_2"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: refresh: removing newly created unreferenced file "_2.fdx"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: refresh: removing newly created unreferenced file "_2.nvd"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: refresh: removing newly created unreferenced file "_2_Lucene50_0.doc"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: delete "segments_2"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.981Z; Thread-1221]: delete "_2.fdx"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.981Z; Thread-1221]: unable to remove file "_2.fdx": java.io.IOException: cannot delete file: _2.fdx, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 2 [2016-02-16T20:22:30.981Z; Thread-1221]: delete "_2_Lucene50_0.doc"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.982Z; Thread-1221]: delete "_2.nvd"
[junit4] 1> IFD 2 [2016-02-16T20:22:30.982Z; Thread-1221]: delete "_2.fdx"
[junit4] 1>
[junit4] 1> TEST: WriterThread iter=2
[junit4] 1> IFD 3 [2016-02-16T20:22:31.001Z; Thread-1221]: init: current segments file is "segments_3"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1f07678
[junit4] 1> IFD 3 [2016-02-16T20:22:31.001Z; Thread-1221]: init: load commit "segments_3"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.004Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1" [3 segments ; isCommit = false]
[junit4] 1> IFD 3 [2016-02-16T20:22:31.004Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IW 3 [2016-02-16T20:22:31.007Z; Thread-1221]: init: create=false
[junit4] 1> IW 3 [2016-02-16T20:22:31.007Z; Thread-1221]:
[junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
[junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
[junit4] 1> version=5.6.0
[junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
[junit4] 1> ramBufferSizeMB=16.0
[junit4] 1> maxBufferedDocs=-1
[junit4] 1> maxBufferedDeleteTerms=-1
[junit4] 1> mergedSegmentWarmer=null
[junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
[junit4] 1> commit=null
[junit4] 1> openMode=APPEND
[junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
[junit4] 1> default WRITE_LOCK_TIMEOUT=0
[junit4] 1> writeLockTimeout=0
[junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
[junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
[junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@64be0a
[junit4] 1> readerPooling=false
[junit4] 1> perThreadHardLimitMB=1945
[junit4] 1> useCompoundFile=true
[junit4] 1> commitOnClose=true
[junit4] 1> writer=org.apache.lucene.index.IndexWriter@1f8994b
[junit4] 1>
[junit4] 1> IW 3 [2016-02-16T20:22:31.007Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 1> IW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: now flush at close
[junit4] 1> IW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: start flush: applyAllDeletes=true
[junit4] 1> IW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
[junit4] 1> DW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: startFullFlush
[junit4] 1> DW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 1> DWFC 3 [2016-02-16T20:22:31.008Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_3, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
[junit4] 1> DWPT 3 [2016-02-16T20:22:31.009Z; Thread-1221]: flush postings as segment _3 numDocs=1
[junit4] 1> IW 3 [2016-02-16T20:22:31.01Z; Thread-1221]: 1 msec to write norms
[junit4] 1> IW 3 [2016-02-16T20:22:31.011Z; Thread-1221]: 0 msec to write docValues
[junit4] 1> IW 3 [2016-02-16T20:22:31.026Z; Thread-1221]: 16 msec to finish stored fields
[junit4] 1> IW 3 [2016-02-16T20:22:31.03Z; Thread-1221]: 4 msec to write postings and finish vectors
[junit4] 1> IW 3 [2016-02-16T20:22:31.032Z; Thread-1221]: 1 msec to write fieldInfos
[junit4] 1> DWPT 3 [2016-02-16T20:22:31.032Z; Thread-1221]: new segment has 0 deleted docs
[junit4] 1> DWPT 3 [2016-02-16T20:22:31.032Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 1> DWPT 3 [2016-02-16T20:22:31.032Z; Thread-1221]: flushedFiles=[_3.nvm, _3_Lucene50_0.tim, _3.nvd, _3_Lucene50_0.tip, _3.fnm, _3.fdx, _3_Lucene50_0.pos, _3.fdt, _3_Lucene50_0.doc]
[junit4] 1> DWPT 3 [2016-02-16T20:22:31.032Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> DWPT 3 [2016-02-16T20:22:31.033Z; Thread-1221]: flushed: segment=_3 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
[junit4] 1> IW 3 [2016-02-16T20:22:31.033Z; Thread-1221]: create compound file
[junit4] 1> DW 3 [2016-02-16T20:22:31.042Z; Thread-1221]: publishFlushedSegment seg-private updates=null
[junit4] 1> IW 3 [2016-02-16T20:22:31.042Z; Thread-1221]: publishFlushedSegment
[junit4] 1> IW 3 [2016-02-16T20:22:31.042Z; Thread-1221]: publish sets newSegment delGen=1 seg=_3(5.6.0):c1
[junit4] 1> IFD 3 [2016-02-16T20:22:31.042Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1" [4 segments ; isCommit = false]
[junit4] 1> IFD 3 [2016-02-16T20:22:31.042Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> DW 3 [2016-02-16T20:22:31.042Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.nvm"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3_Lucene50_0.tim"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.nvd"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3_Lucene50_0.tip"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.fnm"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.fdx"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3_Lucene50_0.pos"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.fdt"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3_Lucene50_0.doc"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: delete "_3_Lucene50_0.tim"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: delete "_3.nvm"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.044Z; Thread-1221]: delete "_3.nvd"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.044Z; Thread-1221]: unable to remove file "_3.nvd": java.io.IOException: cannot delete file: _3.nvd, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 3 [2016-02-16T20:22:31.044Z; Thread-1221]: delete "_3_Lucene50_0.tip"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.045Z; Thread-1221]: delete "_3.fnm"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.045Z; Thread-1221]: unable to remove file "_3.fnm": java.io.IOException: cannot delete file: _3.fnm, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 3 [2016-02-16T20:22:31.045Z; Thread-1221]: delete "_3.fdx"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.045Z; Thread-1221]: delete "_3_Lucene50_0.pos"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: delete "_3.fdt"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: delete "_3_Lucene50_0.doc"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: unable to remove file "_3_Lucene50_0.doc": java.io.IOException: cannot delete file: _3_Lucene50_0.doc, a virus scanner has it open; Will re-try later.
[junit4] 1> IW 3 [2016-02-16T20:22:31.046Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 3 [2016-02-16T20:22:31.046Z; Thread-1221]: now apply all deletes for all segments maxDoc=4
[junit4] 1> BD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 3 [2016-02-16T20:22:31.047Z; Thread-1221]: prune sis=segments_3: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> TMP 3 [2016-02-16T20:22:31.047Z; Thread-1221]: findMerges: 4 segments
[junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: seg=_3(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: allowedSegmentCount=1 vs count=4 (eligible count=4) tooBigCount=0
[junit4] 1> MS 3 [2016-02-16T20:22:31.048Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
[junit4] 1> MS 3 [2016-02-16T20:22:31.048Z; Thread-1221]: now merge
[junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
[junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: no more merges pending; now return
[junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
[junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: now merge
[junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
[junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: no more merges pending; now return
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: waitForMerges
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: waitForMerges done
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: commit: start
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: commit: enter lock
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: commit: now prepare
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: prepareCommit: flush
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
[junit4] 1> DW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: startFullFlush
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: now apply all deletes for all segments maxDoc=4
[junit4] 1> BD 3 [2016-02-16T20:22:31.049Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 3 [2016-02-16T20:22:31.049Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 3 [2016-02-16T20:22:31.05Z; Thread-1221]: prune sis=segments_3: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> DW 3 [2016-02-16T20:22:31.05Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IW 3 [2016-02-16T20:22:31.05Z; Thread-1221]: startCommit(): start
[junit4] 1> IW 3 [2016-02-16T20:22:31.05Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 changeCount=3
[junit4] 1> IW 3 [2016-02-16T20:22:31.054Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_4"
[junit4] 1> IW 3 [2016-02-16T20:22:31.054Z; Thread-1221]: done all syncs: [_2.si, _3.si, _3.cfe, _1.si, _0.cfe, _2.cfe, _2.cfs, _1.cfe, _0.si, _3.cfs, _1.cfs, _0.cfs]
[junit4] 1> IW 3 [2016-02-16T20:22:31.054Z; Thread-1221]: commit: pendingCommit != null
[junit4] 1> IW 3 [2016-02-16T20:22:31.055Z; Thread-1221]: commit: done writing segments file "segments_4"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.055Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1" [4 segments ; isCommit = true]
[junit4] 1> IFD 3 [2016-02-16T20:22:31.055Z; Thread-1221]: deleteCommits: now decRef commit "segments_3"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.055Z; Thread-1221]: delete "segments_3"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.055Z; Thread-1221]: delete "_3.nvd"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.056Z; Thread-1221]: delete "_3.fnm"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.056Z; Thread-1221]: delete "_3_Lucene50_0.doc"
[junit4] 1> IFD 3 [2016-02-16T20:22:31.056Z; Thread-1221]: 1 msec to checkpoint
[junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: commit: took 8.1 msec
[junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: commit: done
[junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: rollback
[junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: all running merges have aborted
[junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: rollback: done finish merges
[junit4] 1> DW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: abort
[junit4] 1> DW 3 [2016-02-16T20:22:31.057Z; Thread-1221]: done abort success=true
[junit4] 1> IW 3 [2016-02-16T20:22:31.057Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
[junit4] 1> IFD 3 [2016-02-16T20:22:31.057Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1" [4 segments ; isCommit = false]
[junit4] 1> IFD 3 [2016-02-16T20:22:31.057Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1>
[junit4] 1> TEST: WriterThread iter=3
[junit4] 1> IFD 4 [2016-02-16T20:22:31.068Z; Thread-1221]: init: current segments file is "segments_4"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@11c721c
[junit4] 1> IFD 4 [2016-02-16T20:22:31.068Z; Thread-1221]: init: load commit "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.074Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1" [4 segments ; isCommit = false]
[junit4] 1> IFD 4 [2016-02-16T20:22:31.074Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IW 4 [2016-02-16T20:22:31.077Z; Thread-1221]: init: create=false
[junit4] 1> IW 4 [2016-02-16T20:22:31.077Z; Thread-1221]:
[junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
[junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
[junit4] 1> version=5.6.0
[junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
[junit4] 1> ramBufferSizeMB=16.0
[junit4] 1> maxBufferedDocs=-1
[junit4] 1> maxBufferedDeleteTerms=-1
[junit4] 1> mergedSegmentWarmer=null
[junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
[junit4] 1> commit=null
[junit4] 1> openMode=APPEND
[junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
[junit4] 1> default WRITE_LOCK_TIMEOUT=0
[junit4] 1> writeLockTimeout=0
[junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
[junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
[junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@37e82f
[junit4] 1> readerPooling=false
[junit4] 1> perThreadHardLimitMB=1945
[junit4] 1> useCompoundFile=true
[junit4] 1> commitOnClose=true
[junit4] 1> writer=org.apache.lucene.index.IndexWriter@6c6f01
[junit4] 1>
[junit4] 1> IW 4 [2016-02-16T20:22:31.078Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 1> IW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: now flush at close
[junit4] 1> IW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: start flush: applyAllDeletes=true
[junit4] 1> IW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
[junit4] 1> DW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: startFullFlush
[junit4] 1> DW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 1> DWFC 4 [2016-02-16T20:22:31.08Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_4, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
[junit4] 1> DWPT 4 [2016-02-16T20:22:31.08Z; Thread-1221]: flush postings as segment _4 numDocs=1
[junit4] 1> IW 4 [2016-02-16T20:22:31.082Z; Thread-1221]: 1 msec to write norms
[junit4] 1> IW 4 [2016-02-16T20:22:31.082Z; Thread-1221]: 0 msec to write docValues
[junit4] 1> IW 4 [2016-02-16T20:22:31.082Z; Thread-1221]: 0 msec to finish stored fields
[junit4] 1> IW 4 [2016-02-16T20:22:31.085Z; Thread-1221]: 2 msec to write postings and finish vectors
[junit4] 1> IW 4 [2016-02-16T20:22:31.086Z; Thread-1221]: 0 msec to write fieldInfos
[junit4] 1> DWPT 4 [2016-02-16T20:22:31.086Z; Thread-1221]: new segment has 0 deleted docs
[junit4] 1> DWPT 4 [2016-02-16T20:22:31.086Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 1> DWPT 4 [2016-02-16T20:22:31.086Z; Thread-1221]: flushedFiles=[_4.fdx, _4.fnm, _4.nvd, _4_Lucene50_0.tip, _4.nvm, _4_Lucene50_0.tim, _4_Lucene50_0.pos, _4.fdt, _4_Lucene50_0.doc]
[junit4] 1> DWPT 4 [2016-02-16T20:22:31.086Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> DWPT 4 [2016-02-16T20:22:31.087Z; Thread-1221]: flushed: segment=_4 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
[junit4] 1> IW 4 [2016-02-16T20:22:31.087Z; Thread-1221]: create compound file
[junit4] 1> DW 4 [2016-02-16T20:22:31.095Z; Thread-1221]: publishFlushedSegment seg-private updates=null
[junit4] 1> IW 4 [2016-02-16T20:22:31.095Z; Thread-1221]: publishFlushedSegment
[junit4] 1> IW 4 [2016-02-16T20:22:31.095Z; Thread-1221]: publish sets newSegment delGen=1 seg=_4(5.6.0):c1
[junit4] 1> IFD 4 [2016-02-16T20:22:31.095Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1" [5 segments ; isCommit = false]
[junit4] 1> IFD 4 [2016-02-16T20:22:31.095Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> DW 4 [2016-02-16T20:22:31.095Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.fdx"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.fnm"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.nvd"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4_Lucene50_0.tip"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.nvm"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4_Lucene50_0.tim"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4_Lucene50_0.pos"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.fdt"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4_Lucene50_0.doc"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: delete "_4.fdx"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: delete "_4.fnm"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: unable to remove file "_4.fnm": java.io.IOException: cannot delete file: _4.fnm, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: delete "_4.nvd"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: unable to remove file "_4.nvd": java.io.IOException: cannot delete file: _4.nvd, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: delete "_4_Lucene50_0.tip"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: delete "_4.nvm"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: unable to remove file "_4.nvm": java.io.IOException: cannot delete file: _4.nvm, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: delete "_4_Lucene50_0.tim"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: delete "_4_Lucene50_0.pos"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: delete "_4.fdt"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.098Z; Thread-1221]: delete "_4_Lucene50_0.doc"
[junit4] 1> IW 4 [2016-02-16T20:22:31.098Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 4 [2016-02-16T20:22:31.098Z; Thread-1221]: now apply all deletes for all segments maxDoc=5
[junit4] 1> BD 4 [2016-02-16T20:22:31.098Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 4 [2016-02-16T20:22:31.098Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 4 [2016-02-16T20:22:31.098Z; Thread-1221]: prune sis=segments_4: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> TMP 4 [2016-02-16T20:22:31.098Z; Thread-1221]: findMerges: 5 segments
[junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_3(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_4(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: allowedSegmentCount=1 vs count=5 (eligible count=5) tooBigCount=0
[junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
[junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: now merge
[junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
[junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: no more merges pending; now return
[junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
[junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: now merge
[junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
[junit4] 1> MS 4 [2016-02-16T20:22:31.101Z; Thread-1221]: no more merges pending; now return
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: waitForMerges
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: waitForMerges done
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: commit: start
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: commit: enter lock
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: commit: now prepare
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: prepareCommit: flush
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
[junit4] 1> DW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: startFullFlush
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: now apply all deletes for all segments maxDoc=5
[junit4] 1> BD 4 [2016-02-16T20:22:31.101Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 4 [2016-02-16T20:22:31.101Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 4 [2016-02-16T20:22:31.101Z; Thread-1221]: prune sis=segments_4: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> DW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: startCommit(): start
[junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 changeCount=3
[junit4] 1> IW 4 [2016-02-16T20:22:31.105Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_5"
[junit4] 1> IW 4 [2016-02-16T20:22:31.106Z; Thread-1221]: done all syncs: [_4.cfs, _2.si, _4.cfe, _3.si, _3.cfe, _1.si, _4.si, _0.cfe, _2.cfe, _2.cfs, _1.cfe, _0.si, _3.cfs, _1.cfs, _0.cfs]
[junit4] 1> IW 4 [2016-02-16T20:22:31.106Z; Thread-1221]: commit: pendingCommit != null
[junit4] 1> IW 4 [2016-02-16T20:22:31.107Z; Thread-1221]: commit: done writing segments file "segments_5"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1" [5 segments ; isCommit = true]
[junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: deleteCommits: now decRef commit "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: delete "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
[junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: delete "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
[junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: commit: took 6.8 msec
[junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: commit: done
[junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: rollback
[junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: all running merges have aborted
[junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: rollback: done finish merges
[junit4] 1> DW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: abort
[junit4] 1> DW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: done abort success=true
[junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
[junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1" [5 segments ; isCommit = false]
[junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: delete "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
[junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: refresh: removing newly created unreferenced file "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: refresh: removing newly created unreferenced file "_4.nvd"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: refresh: removing newly created unreferenced file "_4.fnm"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: refresh: removing newly created unreferenced file "_4.nvm"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: delete "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: delete "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: delete "segments_4"
[junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
[junit4] 1> IFD 4 [2016-02-16T20:22:31.11Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
[junit4] 1>
[junit4] 1> TEST: WriterThread iter=4
[junit4] 1> IFD 5 [2016-02-16T20:22:31.12Z; Thread-1221]: init: current segments file is "segments_5"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@23dd2b
[junit4] 1> IFD 5 [2016-02-16T20:22:31.12Z; Thread-1221]: init: load commit "segments_4"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.136Z; Thread-1221]: init: load commit "segments_5"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: init: removing unreferenced file "_4.nvd"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: delete "_4.nvd"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: unable to remove file "_4.nvd": java.io.IOException: cannot delete file: _4.nvd, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: init: removing unreferenced file "_4.nvm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: delete "_4.nvm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: init: removing unreferenced file "_4.fnm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: delete "_4.fnm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.141Z; Thread-1221]: unable to remove file "_4.fnm": java.io.IOException: cannot delete file: _4.fnm, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 5 [2016-02-16T20:22:31.141Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1" [5 segments ; isCommit = false]
[junit4] 1> IFD 5 [2016-02-16T20:22:31.141Z; Thread-1221]: delete "_4.fnm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.141Z; Thread-1221]: delete "_4.nvd"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.142Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IFD 5 [2016-02-16T20:22:31.142Z; Thread-1221]: deleteCommits: now decRef commit "segments_4"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.142Z; Thread-1221]: delete "segments_4"
[junit4] 1> IW 5 [2016-02-16T20:22:31.148Z; Thread-1221]: init: create=false
[junit4] 1> IW 5 [2016-02-16T20:22:31.148Z; Thread-1221]:
[junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
[junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
[junit4] 1> version=5.6.0
[junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
[junit4] 1> ramBufferSizeMB=16.0
[junit4] 1> maxBufferedDocs=-1
[junit4] 1> maxBufferedDeleteTerms=-1
[junit4] 1> mergedSegmentWarmer=null
[junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
[junit4] 1> commit=null
[junit4] 1> openMode=APPEND
[junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
[junit4] 1> default WRITE_LOCK_TIMEOUT=0
[junit4] 1> writeLockTimeout=0
[junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
[junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
[junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@1e2b62
[junit4] 1> readerPooling=false
[junit4] 1> perThreadHardLimitMB=1945
[junit4] 1> useCompoundFile=true
[junit4] 1> commitOnClose=true
[junit4] 1> writer=org.apache.lucene.index.IndexWriter@b2590c
[junit4] 1>
[junit4] 1> IW 5 [2016-02-16T20:22:31.148Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 1> IW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: now flush at close
[junit4] 1> IW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: start flush: applyAllDeletes=true
[junit4] 1> IW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
[junit4] 1> DW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: startFullFlush
[junit4] 1> DW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 1> DWFC 5 [2016-02-16T20:22:31.15Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_5, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
[junit4] 1> DWPT 5 [2016-02-16T20:22:31.15Z; Thread-1221]: flush postings as segment _5 numDocs=1
[junit4] 1> IW 5 [2016-02-16T20:22:31.153Z; Thread-1221]: 2 msec to write norms
[junit4] 1> IW 5 [2016-02-16T20:22:31.153Z; Thread-1221]: 0 msec to write docValues
[junit4] 1> IW 5 [2016-02-16T20:22:31.154Z; Thread-1221]: 1 msec to finish stored fields
[junit4] 1> IW 5 [2016-02-16T20:22:31.157Z; Thread-1221]: 2 msec to write postings and finish vectors
[junit4] 1> IW 5 [2016-02-16T20:22:31.158Z; Thread-1221]: 0 msec to write fieldInfos
[junit4] 1> DWPT 5 [2016-02-16T20:22:31.158Z; Thread-1221]: new segment has 0 deleted docs
[junit4] 1> DWPT 5 [2016-02-16T20:22:31.158Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 1> DWPT 5 [2016-02-16T20:22:31.158Z; Thread-1221]: flushedFiles=[_5.fnm, _5_Lucene50_0.tip, _5.nvm, _5_Lucene50_0.doc, _5.nvd, _5.fdt, _5.fdx, _5_Lucene50_0.pos, _5_Lucene50_0.tim]
[junit4] 1> DWPT 5 [2016-02-16T20:22:31.158Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> DWPT 5 [2016-02-16T20:22:31.159Z; Thread-1221]: flushed: segment=_5 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
[junit4] 1> IW 5 [2016-02-16T20:22:31.159Z; Thread-1221]: create compound file
[junit4] 1> DW 5 [2016-02-16T20:22:31.189Z; Thread-1221]: publishFlushedSegment seg-private updates=null
[junit4] 1> IW 5 [2016-02-16T20:22:31.189Z; Thread-1221]: publishFlushedSegment
[junit4] 1> IW 5 [2016-02-16T20:22:31.189Z; Thread-1221]: publish sets newSegment delGen=1 seg=_5(5.6.0):c1
[junit4] 1> IFD 5 [2016-02-16T20:22:31.189Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1" [6 segments ; isCommit = false]
[junit4] 1> IFD 5 [2016-02-16T20:22:31.189Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> DW 5 [2016-02-16T20:22:31.19Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.fnm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5_Lucene50_0.tip"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.nvm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5_Lucene50_0.doc"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.nvd"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.fdt"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.fdx"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5_Lucene50_0.pos"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5_Lucene50_0.tim"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: delete "_5.fnm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: delete "_5_Lucene50_0.tip"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: delete "_5.nvm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: unable to remove file "_5.nvm": java.io.IOException: cannot delete file: _5.nvm, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: delete "_5_Lucene50_0.doc"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: unable to remove file "_5_Lucene50_0.doc": java.io.IOException: cannot delete file: _5_Lucene50_0.doc, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: delete "_5.nvd"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.192Z; Thread-1221]: delete "_5.fdt"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.192Z; Thread-1221]: delete "_5_Lucene50_0.pos"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.192Z; Thread-1221]: delete "_5.fdx"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: delete "_5_Lucene50_0.tim"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: unable to remove file "_5_Lucene50_0.tim": java.io.IOException: cannot delete file: _5_Lucene50_0.tim, a virus scanner has it open; Will re-try later.
[junit4] 1> IW 5 [2016-02-16T20:22:31.193Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 5 [2016-02-16T20:22:31.193Z; Thread-1221]: now apply all deletes for all segments maxDoc=6
[junit4] 1> BD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: prune sis=segments_5: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> TMP 5 [2016-02-16T20:22:31.193Z; Thread-1221]: findMerges: 6 segments
[junit4] 1> TMP 5 [2016-02-16T20:22:31.194Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_3(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_4(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_5(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: allowedSegmentCount=1 vs count=6 (eligible count=6) tooBigCount=0
[junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
[junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: now merge
[junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
[junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: no more merges pending; now return
[junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
[junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: now merge
[junit4] 1> MS 5 [2016-02-16T20:22:31.197Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
[junit4] 1> MS 5 [2016-02-16T20:22:31.197Z; Thread-1221]: no more merges pending; now return
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: waitForMerges
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: waitForMerges done
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: commit: start
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: commit: enter lock
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: commit: now prepare
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: prepareCommit: flush
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
[junit4] 1> DW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: startFullFlush
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: now apply all deletes for all segments maxDoc=6
[junit4] 1> BD 5 [2016-02-16T20:22:31.197Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 5 [2016-02-16T20:22:31.197Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 5 [2016-02-16T20:22:31.197Z; Thread-1221]: prune sis=segments_5: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> DW 5 [2016-02-16T20:22:31.198Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IW 5 [2016-02-16T20:22:31.198Z; Thread-1221]: startCommit(): start
[junit4] 1> IW 5 [2016-02-16T20:22:31.198Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 changeCount=3
[junit4] 1> IW 5 [2016-02-16T20:22:31.207Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_6"
[junit4] 1> IW 5 [2016-02-16T20:22:31.208Z; Thread-1221]: done all syncs: [_4.cfs, _2.si, _1.si, _3.si, _0.cfe, _5.cfe, _2.cfs, _3.cfs, _1.cfs, _0.cfs, _5.si, _4.cfe, _3.cfe, _4.si, _5.cfs, _2.cfe, _0.si, _1.cfe]
[junit4] 1> IW 5 [2016-02-16T20:22:31.208Z; Thread-1221]: commit: pendingCommit != null
[junit4] 1> IW 5 [2016-02-16T20:22:31.209Z; Thread-1221]: commit: done writing segments file "segments_6"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.209Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1" [6 segments ; isCommit = true]
[junit4] 1> IFD 5 [2016-02-16T20:22:31.209Z; Thread-1221]: deleteCommits: now decRef commit "segments_5"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.209Z; Thread-1221]: delete "segments_5"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.21Z; Thread-1221]: delete "_5.nvm"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.21Z; Thread-1221]: delete "_5_Lucene50_0.doc"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.21Z; Thread-1221]: delete "_5_Lucene50_0.tim"
[junit4] 1> IFD 5 [2016-02-16T20:22:31.211Z; Thread-1221]: 1 msec to checkpoint
[junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: commit: took 13.5 msec
[junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: commit: done
[junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: rollback
[junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: all running merges have aborted
[junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: rollback: done finish merges
[junit4] 1> DW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: abort
[junit4] 1> DW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: done abort success=true
[junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
[junit4] 1> IFD 5 [2016-02-16T20:22:31.211Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1" [6 segments ; isCommit = false]
[junit4] 1> IFD 5 [2016-02-16T20:22:31.211Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1>
[junit4] 1> TEST: WriterThread iter=5
[junit4] 1> IFD 6 [2016-02-16T20:22:31.244Z; Thread-1221]: init: current segments file is "segments_6"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1a57a74
[junit4] 1> IFD 6 [2016-02-16T20:22:31.244Z; Thread-1221]: init: load commit "segments_6"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.25Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1" [6 segments ; isCommit = false]
[junit4] 1> IFD 6 [2016-02-16T20:22:31.25Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IW 6 [2016-02-16T20:22:31.327Z; Thread-1221]: init: create=false
[junit4] 1> IW 6 [2016-02-16T20:22:31.327Z; Thread-1221]:
[junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
[junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
[junit4] 1> version=5.6.0
[junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
[junit4] 1> ramBufferSizeMB=16.0
[junit4] 1> maxBufferedDocs=-1
[junit4] 1> maxBufferedDeleteTerms=-1
[junit4] 1> mergedSegmentWarmer=null
[junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
[junit4] 1> commit=null
[junit4] 1> openMode=APPEND
[junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
[junit4] 1> default WRITE_LOCK_TIMEOUT=0
[junit4] 1> writeLockTimeout=0
[junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
[junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
[junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@1df36ce
[junit4] 1> readerPooling=false
[junit4] 1> perThreadHardLimitMB=1945
[junit4] 1> useCompoundFile=true
[junit4] 1> commitOnClose=true
[junit4] 1> writer=org.apache.lucene.index.IndexWriter@18724e2
[junit4] 1>
[junit4] 1> IW 6 [2016-02-16T20:22:31.327Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 1> IW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: now flush at close
[junit4] 1> IW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: start flush: applyAllDeletes=true
[junit4] 1> IW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
[junit4] 1> DW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: startFullFlush
[junit4] 1> DW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 1> DWFC 6 [2016-02-16T20:22:31.329Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_6, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
[junit4] 1> DWPT 6 [2016-02-16T20:22:31.33Z; Thread-1221]: flush postings as segment _6 numDocs=1
[junit4] 1> IW 6 [2016-02-16T20:22:31.341Z; Thread-1221]: 9 msec to write norms
[junit4] 1> IW 6 [2016-02-16T20:22:31.341Z; Thread-1221]: 0 msec to write docValues
[junit4] 1> IW 6 [2016-02-16T20:22:31.341Z; Thread-1221]: 0 msec to finish stored fields
[junit4] 1> IW 6 [2016-02-16T20:22:31.345Z; Thread-1221]: 3 msec to write postings and finish vectors
[junit4] 1> IW 6 [2016-02-16T20:22:31.345Z; Thread-1221]: 0 msec to write fieldInfos
[junit4] 1> DWPT 6 [2016-02-16T20:22:31.345Z; Thread-1221]: new segment has 0 deleted docs
[junit4] 1> DWPT 6 [2016-02-16T20:22:31.345Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 1> DWPT 6 [2016-02-16T20:22:31.345Z; Thread-1221]: flushedFiles=[_6.fdx, _6.fnm, _6_Lucene50_0.pos, _6.nvd, _6_Lucene50_0.tim, _6.fdt, _6.nvm, _6_Lucene50_0.tip, _6_Lucene50_0.doc]
[junit4] 1> DWPT 6 [2016-02-16T20:22:31.346Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
[junit4] 1> DWPT 6 [2016-02-16T20:22:31.346Z; Thread-1221]: flushed: segment=_6 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
[junit4] 1> IW 6 [2016-02-16T20:22:31.346Z; Thread-1221]: create compound file
[junit4] 1> DW 6 [2016-02-16T20:22:31.361Z; Thread-1221]: publishFlushedSegment seg-private updates=null
[junit4] 1> IW 6 [2016-02-16T20:22:31.361Z; Thread-1221]: publishFlushedSegment
[junit4] 1> IW 6 [2016-02-16T20:22:31.361Z; Thread-1221]: publish sets newSegment delGen=1 seg=_6(5.6.0):c1
[junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 _6(5.6.0):c1" [7 segments ; isCommit = false]
[junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> DW 6 [2016-02-16T20:22:31.361Z; Thread-1221]: Thread-1221 finishFullFlush success=true
[junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: will delete new file "_6.fdx"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: will delete new file "_6.fnm"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: will delete new file "_6_Lucene50_0.pos"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6.nvd"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6_Lucene50_0.tim"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6.fdt"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6.nvm"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6_Lucene50_0.tip"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6_Lucene50_0.doc"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: delete "_6.fdx"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: unable to remove file "_6.fdx": java.io.IOException: cannot delete file: _6.fdx, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: delete "_6.fnm"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6_Lucene50_0.pos"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6_Lucene50_0.tim"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6.nvd"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: unable to remove file "_6.nvd": java.io.IOException: cannot delete file: _6.nvd, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6.fdt"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6.nvm"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: unable to remove file "_6.nvm": java.io.IOException: cannot delete file: _6.nvm, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: delete "_6_Lucene50_0.tip"
[junit4] 1> IFD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: unable to remove file "_6_Lucene50_0.tip": java.io.IOException: cannot delete file: _6_Lucene50_0.tip, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: delete "_6_Lucene50_0.doc"
[junit4] 1> IW 6 [2016-02-16T20:22:31.364Z; Thread-1221]: apply all deletes during flush
[junit4] 1> IW 6 [2016-02-16T20:22:31.364Z; Thread-1221]: now apply all deletes for all segments maxDoc=7
[junit4] 1> BD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
[junit4] 1> BD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: applyDeletes: no segments; skipping
[junit4] 1> BD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: prune sis=segments_6: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 _6(5.6.0):c1 minGen=0 packetCount=0
[junit4] 1> TMP 6 [2016-02-16T20:22:31.364Z; Thread-1221]: findMerges: 7 segments
[junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_3(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_4(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_5(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_6(5.6.0):c1 size=0.001 MB [floored]
[junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: allowedSegmentCount=1 vs count=7 (eligible count=7) tooBigCount=0
[junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
[junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: now merge
[junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 _6(5.6.0):c1
[junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: no more merges pending; now return
[junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
[junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: now merge
[junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-12
[...truncated too long message...]
):c1
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: now checkpoint "_k(5.6.0):c19 _l(5.6.0):c1 _m(5.6.0):c1 _n(5.6.0):c1 _o(5.6.0):c1 _p(5.6.0):c1 _q(5.6.0):c1 _r(5.6.0):c1" [8 segments ; isCommit = false]
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: delete "segments_p"
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: delete "_r_Lucene50_0.pos"
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: unable to remove file "_r_Lucene50_0.pos": java.io.IOException: cannot delete file: _r_Lucene50_0.pos, a virus scanner has it open; Will re-try later.
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: 0 msec to checkpoint
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: refresh: removing newly created unreferenced file "_r_Lucene50_0.pos"
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: refresh: removing newly created unreferenced file "segments_p"
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: delete "segments_p"
[junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: unable to remove file "segments_p": java.nio.file.AccessDeniedException: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001\segments_p; Will re-try later.
[junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: failed to remove commit point "segments_p"; skipping deletion of all other pending files
[junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: delete "segments_p"
[junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: unable to remove file "segments_p": java.nio.file.AccessDeniedException: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001\segments_p; Will re-try later.
[junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: failed to remove commit point "segments_p"; skipping deletion of all other pending files
[junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: delete "segments_p"
[junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: unable to remove file "segments_p": java.nio.file.AccessDeniedException: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001\segments_p; Will re-try later.
[junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: failed to remove commit point "segments_p"; skipping deletion of all other pending files
[junit4] 1>
[junit4] 1> TEST: WriterThread iter=25
[junit4] 1> IFD 26 [2016-02-16T20:22:32.934Z; Thread-1221]: init: current segments file is "segments_q"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1402ba8
[junit4] 1> IFD 26 [2016-02-16T20:22:32.934Z; Thread-1221]: init: load commit "segments_p"
[junit4] 1> IW 26 [2016-02-16T20:22:32.934Z; Thread-1221]: init: hit exception on init; releasing write lock
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestNativeFSLockFactory -Dtests.method=testStressLocks -Dtests.seed=9BA6F0917BCE9B90 -Dtests.slow=true -Dtests.locale=es-GT -Dtests.timezone=America/Lima -Dtests.asserts=true -Dtests.file.encoding=Cp1252
[junit4] FAILURE 3.06s J1 | TestNativeFSLockFactory.testStressLocks <<<
[junit4] > Throwable #1: java.lang.AssertionError: IndexWriter hit unexpected exceptions
[junit4] > at __randomizedtesting.SeedInfo.seed([9BA6F0917BCE9B90:C597BE6C676253F6]:0)
[junit4] > at org.apache.lucene.store.BaseLockFactoryTestCase.testStressLocks(BaseLockFactoryTestCase.java:174)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}, sim=DefaultSimilarity, locale=es-GT, timezone=America/Lima
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_80 (32-bit)/cpus=3,threads=1,free=199458248,total=285425664
[junit4] 2> NOTE: All tests run in this JVM: [TestWildcard, Test2BPositions, TestExceedMaxTermLength, TestPerFieldDocValuesFormat, TestFilteredQuery, TestTieredMergePolicy, TestFixedBitDocIdSet, TestNumericRangeQuery32, TestSpanExplanations, MultiCollectorTest, TestSloppyPhraseQuery, TestTragicIndexWriterDeadlock, TestMultiValuedNumericRangeQuery, TestDemoParallelLeafReader, TestMergeSchedulerExternal, TestIndexWriterForceMerge, TestElevationComparator, TestBlockPostingsFormat, TestBooleanQuery, TestInPlaceMergeSorter, TestReqExclBulkScorer, TestSearchAfter, TestIndexWriterOutOfFileDescriptors, TestBytesRefHash, TestRateLimiter, TestSentinelIntSet, TestMultiset, TestFastCompressionMode, TestPrefixFilter, TestPackedInts, TestUnicodeUtil, TestIndexWriterOnDiskFull, TestRoaringDocIdSet, TestDisjunctionMaxQuery, TestBooleanMinShouldMatch, TestIntroSorter, TestByteSlices, TestTopDocsCollector, TestRecyclingByteBlockAllocator, TestHighCompressionMode, TestFlex, TestIntsRef, TestPositionIncrement, Test2BSortedDocValuesOrds, TestPayloads, TestMultiCollector, TestToken, TestIndexWriterReader, TestAllFilesHaveCodecHeader, TestDocValuesRewriteMethod, TestCompiledAutomaton, TestNoMergePolicy, TestLevenshteinAutomata, TestMixedDocValuesUpdates, TestPrefixQuery, TestNot, TestSameTokenSamePosition, TestDirectMonotonic, TestPhrasePrefixQuery, TestPersistentSnapshotDeletionPolicy, TestLongPostings, Test2BPostings, TestStressIndexing, Test2BBinaryDocValues, TestCharFilter, TestDirectory, TestMultiLevelSkipList, TestBitDocIdSetBuilder, TestIndexCommit, TestBoostQuery, TestIndexWriterExceptions2, TestVirtualMethod, TestBooleanCoord, TestCustomSearcherSort, TestSimilarityProvider, TestSpansEnum, TestNRTCachingDirectory, TestDocumentsWriterStallControl, TestLongBitSet, TestRegexpRandom2, TestCheckIndex, Test2BPagedBytes, TestByteArrayDataInput, TestMatchNoDocsQuery, TestIndexReaderClose, TestFieldReuse, TestNearSpansOrdered, TestCrashCausesCorruptIndex, TestPostingsOffsets, TestSizeBoundedForceMerge, TestQueryCachingPolicy, TestSortedNumericSortField, TestNumericUtils, TestIndexWriterMergePolicy, TestDocValuesScoring, TestNumericRangeQuery64, TestStressAdvance, TestCachingWrapperFilter, TestForTooMuchCloning, TestFilterDirectory, TestNRTThreads, TestTermVectors, TestMatchAllDocsQuery, TestTimSorter, TestMergePolicyWrapper, TestFSTs, TestBytesStore, TestIndexWriterWithThreads, TestAddIndexes, TestIndexWriterExceptions, TestMultiMMap, TestSearcherManager, TestDeletionPolicy, TestBooleanOr, TestBasics, TestFlushByRamOrCountsPolicy, TestIndexWriterDelete, TestIndexWriterCommit, TestDirectoryReaderReopen, TestTimeLimitingCollector, TestConcurrentMergeScheduler, TestNeverDelete, TestMinimize, TestRollingUpdates, TestDocTermOrdsRewriteMethod, TestSnapshotDeletionPolicy, TestIndexWriterUnicode, TestNRTReaderWithThreads, TestConsistentFieldNumbers, TestSimpleExplanations, TestDirectoryReader, TestLockFactory, TestSegmentMerger, TestPhraseQuery, TestCollectionUtil, TestBagOfPositions, TestFixedBitSet, TestComplexExplanations, TestSegmentReader, TestFastDecompressionMode, TestFieldCacheRewriteMethod, TestPagedBytes, TestCrash, TestSegmentTermDocs, TestPerFieldPostingsFormat2, TestSort, TestDocValuesIndexing, TestHugeRamFile, TestCodecs, TestParallelLeafReader, TestStressNRT, TestIndexInput, TestForceMergeForever, TestSameScoresWithThreads, TestMultiFields, TestDocumentsWriterDeleteQueue, TestLiveFieldValues, TestDoc, TestExternalCodecs, TestSimpleExplanationsOfNonMatches, TestTermVectorsReader, TestPerSegmentDeletes, TestPrefixInBooleanQuery, TestPrefixCodedTerms, TestParallelReaderEmptyIndex, TestDocument, TestTopFieldCollector, TestFileSwitchDirectory, TestDateSort, TestSmallFloat, TestSearch, TestSpansAdvanced, TestDateFilter, TestCharsRef, TestBinaryDocument, TestAutomatonQueryUnicode, TestRamUsageEstimator, TestIsCurrent, TestIndexWriterLockRelease, TestDemo, TestIndexWriterOnJRECrash, TestCodecHoldsOpenFiles, TestScoreCachingWrappingScorer, TestIOUtils, TestBytesRefAttImpl, TestLucene50CompoundFormat, TestMergeRateLimiter, TestNRTReaderCleanup, TestOrdinalMap, TestReadOnlyIndex, TestStressDeletes, FuzzyTermOnShortTermsTest, TestConjunctionDISI, TestSortedSetSortField, TestBM25Similarity, TestFilterSpans, TestSpanCollection, TestSpanNearQuery, TestSpanOrQuery, TestNativeFSLockFactory]
[junit4] Completed [401/421 (1!)] on J1 in 10.62s, 10 tests, 1 failure <<< FAILURES!
[...truncated 72 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\build.xml:750: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\build.xml:694: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\build.xml:59: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build.xml:50: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\common-build.xml:1477: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\common-build.xml:1033: There were test failures: 421 suites (1 ignored), 3386 tests, 1 failure, 56 ignored (52 assumptions) [seed: 9BA6F0917BCE9B90]
Total time: 6 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
Re: [JENKINS] Lucene-Solr-5.x-Windows (32bit/jdk1.7.0_80) - Build #
5490 - Still Failing!
Posted by Michael McCandless <lu...@mikemccandless.com>.
This is a failure on 5.x, so it's not the "Directory owns delete
retry" change (LUCENE-6835) since that is only on master.
What happens here is: IW needs to delete segments_p since it just
wrote segments_q.
However, an IR has segments_p open, and so windows refuses to delete
(AccessDeniedException), because we are using MMapDirectory.
But this puts segments_p into a screwy state on Windows: it *is*
included in Directory.listAll, but when you try to open it, you hit
FNFE.
I really don't know how we can fix this for 5.x ... the fix in master
is cleaner (but too large to backport) since it ensures segments_p
won't be in listAll result if we had tried to delete it, since the
Directory "owns" the retrying.
Mike McCandless
http://blog.mikemccandless.com
On Tue, Feb 16, 2016 at 3:23 PM, Policeman Jenkins Server
<je...@thetaphi.de> wrote:
> Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-Windows/5490/
> Java: 32bit/jdk1.7.0_80 -server -XX:+UseSerialGC
>
> 1 tests failed.
> FAILED: org.apache.lucene.store.TestNativeFSLockFactory.testStressLocks
>
> Error Message:
> IndexWriter hit unexpected exceptions
>
> Stack Trace:
> java.lang.AssertionError: IndexWriter hit unexpected exceptions
> at __randomizedtesting.SeedInfo.seed([9BA6F0917BCE9B90:C597BE6C676253F6]:0)
> at org.junit.Assert.fail(Assert.java:93)
> at org.junit.Assert.assertTrue(Assert.java:43)
> at org.apache.lucene.store.BaseLockFactoryTestCase.testStressLocks(BaseLockFactoryTestCase.java:174)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
> 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:367)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
> 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:367)
> at java.lang.Thread.run(Thread.java:745)
>
>
>
>
> Build Log:
> [...truncated 1513 lines...]
> [junit4] Suite: org.apache.lucene.store.TestNativeFSLockFactory
> [junit4] 1> Stress Test Index Writer: creation hit unexpected exception: java.io.FileNotFoundException: segments_p in dir=MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653
> [junit4] 1> java.io.FileNotFoundException: segments_p in dir=MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653
> [junit4] 1> at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:640)
> [junit4] 1> at org.apache.lucene.store.Directory.openChecksumInput(Directory.java:109)
> [junit4] 1> at org.apache.lucene.store.MockDirectoryWrapper.openChecksumInput(MockDirectoryWrapper.java:1009)
> [junit4] 1> at org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:294)
> [junit4] 1> at org.apache.lucene.index.IndexFileDeleter.<init>(IndexFileDeleter.java:171)
> [junit4] 1> at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:949)
> [junit4] 1> at org.apache.lucene.store.BaseLockFactoryTestCase$WriterThread.run(BaseLockFactoryTestCase.java:229)
> [junit4] 1>
> [junit4] 1> TEST: WriterThread iter=0
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.901Z; Thread-1221]: init: current segments file is "segments_1"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1d38cd
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.901Z; Thread-1221]: init: load commit "segments_1"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.902Z; Thread-1221]: now checkpoint "_0(5.6.0):c1" [1 segments ; isCommit = false]
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.902Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IW 1 [2016-02-16T20:22:30.903Z; Thread-1221]: init: create=false
> [junit4] 1> IW 1 [2016-02-16T20:22:30.903Z; Thread-1221]:
> [junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
> [junit4] 1> index=_0(5.6.0):c1
> [junit4] 1> version=5.6.0
> [junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
> [junit4] 1> ramBufferSizeMB=16.0
> [junit4] 1> maxBufferedDocs=-1
> [junit4] 1> maxBufferedDeleteTerms=-1
> [junit4] 1> mergedSegmentWarmer=null
> [junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
> [junit4] 1> commit=null
> [junit4] 1> openMode=APPEND
> [junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
> [junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
> [junit4] 1> default WRITE_LOCK_TIMEOUT=0
> [junit4] 1> writeLockTimeout=0
> [junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
> [junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
> [junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@1b4a0ca
> [junit4] 1> readerPooling=false
> [junit4] 1> perThreadHardLimitMB=1945
> [junit4] 1> useCompoundFile=true
> [junit4] 1> commitOnClose=true
> [junit4] 1> writer=org.apache.lucene.index.IndexWriter@1a832c0
> [junit4] 1>
> [junit4] 1> IW 1 [2016-02-16T20:22:30.903Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
> [junit4] 1> IW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: now flush at close
> [junit4] 1> IW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: start flush: applyAllDeletes=true
> [junit4] 1> IW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: index before flush _0(5.6.0):c1
> [junit4] 1> DW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: startFullFlush
> [junit4] 1> DW 1 [2016-02-16T20:22:30.906Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
> [junit4] 1> DWFC 1 [2016-02-16T20:22:30.906Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
> [junit4] 1> DWPT 1 [2016-02-16T20:22:30.906Z; Thread-1221]: flush postings as segment _1 numDocs=1
> [junit4] 1> IW 1 [2016-02-16T20:22:30.907Z; Thread-1221]: 1 msec to write norms
> [junit4] 1> IW 1 [2016-02-16T20:22:30.907Z; Thread-1221]: 0 msec to write docValues
> [junit4] 1> IW 1 [2016-02-16T20:22:30.91Z; Thread-1221]: 2 msec to finish stored fields
> [junit4] 1> IW 1 [2016-02-16T20:22:30.916Z; Thread-1221]: 5 msec to write postings and finish vectors
> [junit4] 1> IW 1 [2016-02-16T20:22:30.917Z; Thread-1221]: 1 msec to write fieldInfos
> [junit4] 1> DWPT 1 [2016-02-16T20:22:30.917Z; Thread-1221]: new segment has 0 deleted docs
> [junit4] 1> DWPT 1 [2016-02-16T20:22:30.917Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
> [junit4] 1> DWPT 1 [2016-02-16T20:22:30.917Z; Thread-1221]: flushedFiles=[_1_Lucene50_0.pos, _1.fdx, _1_Lucene50_0.doc, _1.fdt, _1.fnm, _1.nvm, _1_Lucene50_0.tip, _1_Lucene50_0.tim, _1.nvd]
> [junit4] 1> DWPT 1 [2016-02-16T20:22:30.917Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> DWPT 1 [2016-02-16T20:22:30.918Z; Thread-1221]: flushed: segment=_1 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
> [junit4] 1> IW 1 [2016-02-16T20:22:30.919Z; Thread-1221]: create compound file
> [junit4] 1> DW 1 [2016-02-16T20:22:30.923Z; Thread-1221]: publishFlushedSegment seg-private updates=null
> [junit4] 1> IW 1 [2016-02-16T20:22:30.924Z; Thread-1221]: publishFlushedSegment
> [junit4] 1> IW 1 [2016-02-16T20:22:30.924Z; Thread-1221]: publish sets newSegment delGen=1 seg=_1(5.6.0):c1
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1" [2 segments ; isCommit = false]
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> DW 1 [2016-02-16T20:22:30.924Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1_Lucene50_0.pos"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.fdx"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1_Lucene50_0.doc"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.fdt"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.fnm"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.nvm"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1_Lucene50_0.tip"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1_Lucene50_0.tim"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: will delete new file "_1.nvd"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: delete "_1_Lucene50_0.pos"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.924Z; Thread-1221]: delete "_1_Lucene50_0.doc"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.925Z; Thread-1221]: delete "_1.fdx"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.925Z; Thread-1221]: delete "_1.fnm"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.925Z; Thread-1221]: delete "_1.fdt"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: delete "_1.nvm"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: unable to remove file "_1.nvm": java.io.IOException: cannot delete file: _1.nvm, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: delete "_1_Lucene50_0.tip"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: delete "_1_Lucene50_0.tim"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.926Z; Thread-1221]: delete "_1.nvd"
> [junit4] 1> IW 1 [2016-02-16T20:22:30.927Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 1 [2016-02-16T20:22:30.927Z; Thread-1221]: now apply all deletes for all segments maxDoc=2
> [junit4] 1> BD 1 [2016-02-16T20:22:30.927Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 1 [2016-02-16T20:22:30.927Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 1 [2016-02-16T20:22:30.927Z; Thread-1221]: prune sis=segments_1: _0(5.6.0):c1 _1(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> TMP 1 [2016-02-16T20:22:30.927Z; Thread-1221]: findMerges: 2 segments
> [junit4] 1> TMP 1 [2016-02-16T20:22:30.928Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 1 [2016-02-16T20:22:30.929Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 1 [2016-02-16T20:22:30.929Z; Thread-1221]: allowedSegmentCount=1 vs count=2 (eligible count=2) tooBigCount=0
> [junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
> [junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: now merge
> [junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1
> [junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
> [junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: now merge
> [junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1
> [junit4] 1> MS 1 [2016-02-16T20:22:30.929Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: waitForMerges
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: waitForMerges done
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: commit: start
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: commit: enter lock
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: commit: now prepare
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: prepareCommit: flush
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1
> [junit4] 1> DW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: startFullFlush
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: now apply all deletes for all segments maxDoc=2
> [junit4] 1> BD 1 [2016-02-16T20:22:30.929Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 1 [2016-02-16T20:22:30.929Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 1 [2016-02-16T20:22:30.929Z; Thread-1221]: prune sis=segments_1: _0(5.6.0):c1 _1(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> DW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IW 1 [2016-02-16T20:22:30.929Z; Thread-1221]: startCommit(): start
> [junit4] 1> IW 1 [2016-02-16T20:22:30.93Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 changeCount=3
> [junit4] 1> IW 1 [2016-02-16T20:22:30.932Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_2"
> [junit4] 1> IW 1 [2016-02-16T20:22:30.932Z; Thread-1221]: done all syncs: [_1.si, _0.cfe, _1.cfe, _0.si, _1.cfs, _0.cfs]
> [junit4] 1> IW 1 [2016-02-16T20:22:30.932Z; Thread-1221]: commit: pendingCommit != null
> [junit4] 1> IW 1 [2016-02-16T20:22:30.934Z; Thread-1221]: commit: done writing segments file "segments_2"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.934Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1" [2 segments ; isCommit = true]
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.934Z; Thread-1221]: deleteCommits: now decRef commit "segments_1"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.934Z; Thread-1221]: delete "segments_1"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.936Z; Thread-1221]: delete "_1.nvm"
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.936Z; Thread-1221]: unable to remove file "_1.nvm": java.io.IOException: cannot delete file: _1.nvm, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.936Z; Thread-1221]: 2 msec to checkpoint
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.936Z; Thread-1221]: delete "_1.nvm"
> [junit4] 1> IW 1 [2016-02-16T20:22:30.936Z; Thread-1221]: commit: took 7.2 msec
> [junit4] 1> IW 1 [2016-02-16T20:22:30.936Z; Thread-1221]: commit: done
> [junit4] 1> IW 1 [2016-02-16T20:22:30.936Z; Thread-1221]: rollback
> [junit4] 1> IW 1 [2016-02-16T20:22:30.936Z; Thread-1221]: all running merges have aborted
> [junit4] 1> IW 1 [2016-02-16T20:22:30.937Z; Thread-1221]: rollback: done finish merges
> [junit4] 1> DW 1 [2016-02-16T20:22:30.937Z; Thread-1221]: abort
> [junit4] 1> DW 1 [2016-02-16T20:22:30.937Z; Thread-1221]: done abort success=true
> [junit4] 1> IW 1 [2016-02-16T20:22:30.937Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.937Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1" [2 segments ; isCommit = false]
> [junit4] 1> IFD 1 [2016-02-16T20:22:30.937Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1>
> [junit4] 1> TEST: WriterThread iter=1
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.94Z; Thread-1221]: init: current segments file is "segments_2"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@56e48d
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.94Z; Thread-1221]: init: load commit "segments_2"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.943Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1" [2 segments ; isCommit = false]
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.943Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IW 2 [2016-02-16T20:22:30.946Z; Thread-1221]: init: create=false
> [junit4] 1> IW 2 [2016-02-16T20:22:30.946Z; Thread-1221]:
> [junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
> [junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1
> [junit4] 1> version=5.6.0
> [junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
> [junit4] 1> ramBufferSizeMB=16.0
> [junit4] 1> maxBufferedDocs=-1
> [junit4] 1> maxBufferedDeleteTerms=-1
> [junit4] 1> mergedSegmentWarmer=null
> [junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
> [junit4] 1> commit=null
> [junit4] 1> openMode=APPEND
> [junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
> [junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
> [junit4] 1> default WRITE_LOCK_TIMEOUT=0
> [junit4] 1> writeLockTimeout=0
> [junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
> [junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
> [junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@1765c5b
> [junit4] 1> readerPooling=false
> [junit4] 1> perThreadHardLimitMB=1945
> [junit4] 1> useCompoundFile=true
> [junit4] 1> commitOnClose=true
> [junit4] 1> writer=org.apache.lucene.index.IndexWriter@1a9969c
> [junit4] 1>
> [junit4] 1> IW 2 [2016-02-16T20:22:30.946Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
> [junit4] 1> IW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: now flush at close
> [junit4] 1> IW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: start flush: applyAllDeletes=true
> [junit4] 1> IW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1
> [junit4] 1> DW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: startFullFlush
> [junit4] 1> DW 2 [2016-02-16T20:22:30.949Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
> [junit4] 1> DWFC 2 [2016-02-16T20:22:30.949Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
> [junit4] 1> DWPT 2 [2016-02-16T20:22:30.949Z; Thread-1221]: flush postings as segment _2 numDocs=1
> [junit4] 1> IW 2 [2016-02-16T20:22:30.951Z; Thread-1221]: 1 msec to write norms
> [junit4] 1> IW 2 [2016-02-16T20:22:30.951Z; Thread-1221]: 0 msec to write docValues
> [junit4] 1> IW 2 [2016-02-16T20:22:30.951Z; Thread-1221]: 0 msec to finish stored fields
> [junit4] 1> IW 2 [2016-02-16T20:22:30.954Z; Thread-1221]: 3 msec to write postings and finish vectors
> [junit4] 1> IW 2 [2016-02-16T20:22:30.957Z; Thread-1221]: 1 msec to write fieldInfos
> [junit4] 1> DWPT 2 [2016-02-16T20:22:30.957Z; Thread-1221]: new segment has 0 deleted docs
> [junit4] 1> DWPT 2 [2016-02-16T20:22:30.957Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
> [junit4] 1> DWPT 2 [2016-02-16T20:22:30.957Z; Thread-1221]: flushedFiles=[_2_Lucene50_0.tim, _2.fdx, _2.nvm, _2_Lucene50_0.doc, _2.fdt, _2_Lucene50_0.tip, _2.fnm, _2_Lucene50_0.pos, _2.nvd]
> [junit4] 1> DWPT 2 [2016-02-16T20:22:30.957Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> DWPT 2 [2016-02-16T20:22:30.958Z; Thread-1221]: flushed: segment=_2 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
> [junit4] 1> IW 2 [2016-02-16T20:22:30.958Z; Thread-1221]: create compound file
> [junit4] 1> DW 2 [2016-02-16T20:22:30.964Z; Thread-1221]: publishFlushedSegment seg-private updates=null
> [junit4] 1> IW 2 [2016-02-16T20:22:30.964Z; Thread-1221]: publishFlushedSegment
> [junit4] 1> IW 2 [2016-02-16T20:22:30.964Z; Thread-1221]: publish sets newSegment delGen=1 seg=_2(5.6.0):c1
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1" [3 segments ; isCommit = false]
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> DW 2 [2016-02-16T20:22:30.964Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2_Lucene50_0.tim"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2.fdx"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2.nvm"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2_Lucene50_0.doc"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2.fdt"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2_Lucene50_0.tip"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2.fnm"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.964Z; Thread-1221]: will delete new file "_2_Lucene50_0.pos"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: will delete new file "_2.nvd"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: delete "_2_Lucene50_0.tim"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: delete "_2.fdx"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: unable to remove file "_2.fdx": java.io.IOException: cannot delete file: _2.fdx, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: delete "_2_Lucene50_0.doc"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: unable to remove file "_2_Lucene50_0.doc": java.io.IOException: cannot delete file: _2_Lucene50_0.doc, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.965Z; Thread-1221]: delete "_2.nvm"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.966Z; Thread-1221]: delete "_2_Lucene50_0.tip"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.966Z; Thread-1221]: delete "_2.fdt"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.966Z; Thread-1221]: delete "_2.fnm"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.967Z; Thread-1221]: delete "_2_Lucene50_0.pos"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.967Z; Thread-1221]: delete "_2.nvd"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.967Z; Thread-1221]: unable to remove file "_2.nvd": java.io.IOException: cannot delete file: _2.nvd, a virus scanner has it open; Will re-try later.
> [junit4] 1> IW 2 [2016-02-16T20:22:30.968Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 2 [2016-02-16T20:22:30.968Z; Thread-1221]: now apply all deletes for all segments maxDoc=3
> [junit4] 1> BD 2 [2016-02-16T20:22:30.968Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 2 [2016-02-16T20:22:30.968Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 2 [2016-02-16T20:22:30.968Z; Thread-1221]: prune sis=segments_2: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> TMP 2 [2016-02-16T20:22:30.968Z; Thread-1221]: findMerges: 3 segments
> [junit4] 1> TMP 2 [2016-02-16T20:22:30.969Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 2 [2016-02-16T20:22:30.969Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 2 [2016-02-16T20:22:30.969Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 2 [2016-02-16T20:22:30.969Z; Thread-1221]: allowedSegmentCount=1 vs count=3 (eligible count=3) tooBigCount=0
> [junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
> [junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: now merge
> [junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
> [junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
> [junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: now merge
> [junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
> [junit4] 1> MS 2 [2016-02-16T20:22:30.97Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> IW 2 [2016-02-16T20:22:30.97Z; Thread-1221]: waitForMerges
> [junit4] 1> IW 2 [2016-02-16T20:22:30.97Z; Thread-1221]: waitForMerges done
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: commit: start
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: commit: enter lock
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: commit: now prepare
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: prepareCommit: flush
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
> [junit4] 1> DW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: startFullFlush
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: now apply all deletes for all segments maxDoc=3
> [junit4] 1> BD 2 [2016-02-16T20:22:30.971Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 2 [2016-02-16T20:22:30.971Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 2 [2016-02-16T20:22:30.971Z; Thread-1221]: prune sis=segments_2: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> DW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: startCommit(): start
> [junit4] 1> IW 2 [2016-02-16T20:22:30.971Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 changeCount=3
> [junit4] 1> IW 2 [2016-02-16T20:22:30.975Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_3"
> [junit4] 1> IW 2 [2016-02-16T20:22:30.976Z; Thread-1221]: done all syncs: [_2.si, _1.si, _0.cfe, _2.cfe, _2.cfs, _1.cfe, _0.si, _1.cfs, _0.cfs]
> [junit4] 1> IW 2 [2016-02-16T20:22:30.976Z; Thread-1221]: commit: pendingCommit != null
> [junit4] 1> IW 2 [2016-02-16T20:22:30.977Z; Thread-1221]: commit: done writing segments file "segments_3"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.977Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1" [3 segments ; isCommit = true]
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.977Z; Thread-1221]: deleteCommits: now decRef commit "segments_2"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.977Z; Thread-1221]: delete "segments_2"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: unable to remove file "segments_2": java.io.IOException: MockDirectoryWrapper: file "segments_2" is still open: cannot delete; Will re-try later.
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: failed to remove commit point "segments_2"; skipping deletion of all other pending files
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: delete "segments_2"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: unable to remove file "segments_2": java.io.IOException: MockDirectoryWrapper: file "segments_2" is still open: cannot delete; Will re-try later.
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.978Z; Thread-1221]: failed to remove commit point "segments_2"; skipping deletion of all other pending files
> [junit4] 1> IW 2 [2016-02-16T20:22:30.978Z; Thread-1221]: commit: took 8.2 msec
> [junit4] 1> IW 2 [2016-02-16T20:22:30.978Z; Thread-1221]: commit: done
> [junit4] 1> IW 2 [2016-02-16T20:22:30.978Z; Thread-1221]: rollback
> [junit4] 1> IW 2 [2016-02-16T20:22:30.978Z; Thread-1221]: all running merges have aborted
> [junit4] 1> IW 2 [2016-02-16T20:22:30.979Z; Thread-1221]: rollback: done finish merges
> [junit4] 1> DW 2 [2016-02-16T20:22:30.979Z; Thread-1221]: abort
> [junit4] 1> DW 2 [2016-02-16T20:22:30.979Z; Thread-1221]: done abort success=true
> [junit4] 1> IW 2 [2016-02-16T20:22:30.979Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1" [3 segments ; isCommit = false]
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: delete "segments_2"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: unable to remove file "segments_2": java.nio.file.AccessDeniedException: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001\segments_2; Will re-try later.
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: failed to remove commit point "segments_2"; skipping deletion of all other pending files
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.979Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: refresh: removing newly created unreferenced file "segments_2"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: refresh: removing newly created unreferenced file "_2.fdx"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: refresh: removing newly created unreferenced file "_2.nvd"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: refresh: removing newly created unreferenced file "_2_Lucene50_0.doc"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.98Z; Thread-1221]: delete "segments_2"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.981Z; Thread-1221]: delete "_2.fdx"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.981Z; Thread-1221]: unable to remove file "_2.fdx": java.io.IOException: cannot delete file: _2.fdx, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.981Z; Thread-1221]: delete "_2_Lucene50_0.doc"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.982Z; Thread-1221]: delete "_2.nvd"
> [junit4] 1> IFD 2 [2016-02-16T20:22:30.982Z; Thread-1221]: delete "_2.fdx"
> [junit4] 1>
> [junit4] 1> TEST: WriterThread iter=2
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.001Z; Thread-1221]: init: current segments file is "segments_3"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1f07678
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.001Z; Thread-1221]: init: load commit "segments_3"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.004Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1" [3 segments ; isCommit = false]
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.004Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IW 3 [2016-02-16T20:22:31.007Z; Thread-1221]: init: create=false
> [junit4] 1> IW 3 [2016-02-16T20:22:31.007Z; Thread-1221]:
> [junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
> [junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
> [junit4] 1> version=5.6.0
> [junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
> [junit4] 1> ramBufferSizeMB=16.0
> [junit4] 1> maxBufferedDocs=-1
> [junit4] 1> maxBufferedDeleteTerms=-1
> [junit4] 1> mergedSegmentWarmer=null
> [junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
> [junit4] 1> commit=null
> [junit4] 1> openMode=APPEND
> [junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
> [junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
> [junit4] 1> default WRITE_LOCK_TIMEOUT=0
> [junit4] 1> writeLockTimeout=0
> [junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
> [junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
> [junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@64be0a
> [junit4] 1> readerPooling=false
> [junit4] 1> perThreadHardLimitMB=1945
> [junit4] 1> useCompoundFile=true
> [junit4] 1> commitOnClose=true
> [junit4] 1> writer=org.apache.lucene.index.IndexWriter@1f8994b
> [junit4] 1>
> [junit4] 1> IW 3 [2016-02-16T20:22:31.007Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
> [junit4] 1> IW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: now flush at close
> [junit4] 1> IW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: start flush: applyAllDeletes=true
> [junit4] 1> IW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1
> [junit4] 1> DW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: startFullFlush
> [junit4] 1> DW 3 [2016-02-16T20:22:31.008Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
> [junit4] 1> DWFC 3 [2016-02-16T20:22:31.008Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_3, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
> [junit4] 1> DWPT 3 [2016-02-16T20:22:31.009Z; Thread-1221]: flush postings as segment _3 numDocs=1
> [junit4] 1> IW 3 [2016-02-16T20:22:31.01Z; Thread-1221]: 1 msec to write norms
> [junit4] 1> IW 3 [2016-02-16T20:22:31.011Z; Thread-1221]: 0 msec to write docValues
> [junit4] 1> IW 3 [2016-02-16T20:22:31.026Z; Thread-1221]: 16 msec to finish stored fields
> [junit4] 1> IW 3 [2016-02-16T20:22:31.03Z; Thread-1221]: 4 msec to write postings and finish vectors
> [junit4] 1> IW 3 [2016-02-16T20:22:31.032Z; Thread-1221]: 1 msec to write fieldInfos
> [junit4] 1> DWPT 3 [2016-02-16T20:22:31.032Z; Thread-1221]: new segment has 0 deleted docs
> [junit4] 1> DWPT 3 [2016-02-16T20:22:31.032Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
> [junit4] 1> DWPT 3 [2016-02-16T20:22:31.032Z; Thread-1221]: flushedFiles=[_3.nvm, _3_Lucene50_0.tim, _3.nvd, _3_Lucene50_0.tip, _3.fnm, _3.fdx, _3_Lucene50_0.pos, _3.fdt, _3_Lucene50_0.doc]
> [junit4] 1> DWPT 3 [2016-02-16T20:22:31.032Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> DWPT 3 [2016-02-16T20:22:31.033Z; Thread-1221]: flushed: segment=_3 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
> [junit4] 1> IW 3 [2016-02-16T20:22:31.033Z; Thread-1221]: create compound file
> [junit4] 1> DW 3 [2016-02-16T20:22:31.042Z; Thread-1221]: publishFlushedSegment seg-private updates=null
> [junit4] 1> IW 3 [2016-02-16T20:22:31.042Z; Thread-1221]: publishFlushedSegment
> [junit4] 1> IW 3 [2016-02-16T20:22:31.042Z; Thread-1221]: publish sets newSegment delGen=1 seg=_3(5.6.0):c1
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.042Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1" [4 segments ; isCommit = false]
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.042Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> DW 3 [2016-02-16T20:22:31.042Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.nvm"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3_Lucene50_0.tim"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.nvd"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3_Lucene50_0.tip"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.fnm"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.fdx"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3_Lucene50_0.pos"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3.fdt"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: will delete new file "_3_Lucene50_0.doc"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: delete "_3_Lucene50_0.tim"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.043Z; Thread-1221]: delete "_3.nvm"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.044Z; Thread-1221]: delete "_3.nvd"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.044Z; Thread-1221]: unable to remove file "_3.nvd": java.io.IOException: cannot delete file: _3.nvd, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.044Z; Thread-1221]: delete "_3_Lucene50_0.tip"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.045Z; Thread-1221]: delete "_3.fnm"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.045Z; Thread-1221]: unable to remove file "_3.fnm": java.io.IOException: cannot delete file: _3.fnm, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.045Z; Thread-1221]: delete "_3.fdx"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.045Z; Thread-1221]: delete "_3_Lucene50_0.pos"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: delete "_3.fdt"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: delete "_3_Lucene50_0.doc"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: unable to remove file "_3_Lucene50_0.doc": java.io.IOException: cannot delete file: _3_Lucene50_0.doc, a virus scanner has it open; Will re-try later.
> [junit4] 1> IW 3 [2016-02-16T20:22:31.046Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 3 [2016-02-16T20:22:31.046Z; Thread-1221]: now apply all deletes for all segments maxDoc=4
> [junit4] 1> BD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 3 [2016-02-16T20:22:31.046Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 3 [2016-02-16T20:22:31.047Z; Thread-1221]: prune sis=segments_3: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> TMP 3 [2016-02-16T20:22:31.047Z; Thread-1221]: findMerges: 4 segments
> [junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: seg=_3(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 3 [2016-02-16T20:22:31.048Z; Thread-1221]: allowedSegmentCount=1 vs count=4 (eligible count=4) tooBigCount=0
> [junit4] 1> MS 3 [2016-02-16T20:22:31.048Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
> [junit4] 1> MS 3 [2016-02-16T20:22:31.048Z; Thread-1221]: now merge
> [junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
> [junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
> [junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: now merge
> [junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
> [junit4] 1> MS 3 [2016-02-16T20:22:31.049Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: waitForMerges
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: waitForMerges done
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: commit: start
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: commit: enter lock
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: commit: now prepare
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: prepareCommit: flush
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
> [junit4] 1> DW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: startFullFlush
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 3 [2016-02-16T20:22:31.049Z; Thread-1221]: now apply all deletes for all segments maxDoc=4
> [junit4] 1> BD 3 [2016-02-16T20:22:31.049Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 3 [2016-02-16T20:22:31.049Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 3 [2016-02-16T20:22:31.05Z; Thread-1221]: prune sis=segments_3: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> DW 3 [2016-02-16T20:22:31.05Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IW 3 [2016-02-16T20:22:31.05Z; Thread-1221]: startCommit(): start
> [junit4] 1> IW 3 [2016-02-16T20:22:31.05Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 changeCount=3
> [junit4] 1> IW 3 [2016-02-16T20:22:31.054Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_4"
> [junit4] 1> IW 3 [2016-02-16T20:22:31.054Z; Thread-1221]: done all syncs: [_2.si, _3.si, _3.cfe, _1.si, _0.cfe, _2.cfe, _2.cfs, _1.cfe, _0.si, _3.cfs, _1.cfs, _0.cfs]
> [junit4] 1> IW 3 [2016-02-16T20:22:31.054Z; Thread-1221]: commit: pendingCommit != null
> [junit4] 1> IW 3 [2016-02-16T20:22:31.055Z; Thread-1221]: commit: done writing segments file "segments_4"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.055Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1" [4 segments ; isCommit = true]
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.055Z; Thread-1221]: deleteCommits: now decRef commit "segments_3"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.055Z; Thread-1221]: delete "segments_3"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.055Z; Thread-1221]: delete "_3.nvd"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.056Z; Thread-1221]: delete "_3.fnm"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.056Z; Thread-1221]: delete "_3_Lucene50_0.doc"
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.056Z; Thread-1221]: 1 msec to checkpoint
> [junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: commit: took 8.1 msec
> [junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: commit: done
> [junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: rollback
> [junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: all running merges have aborted
> [junit4] 1> IW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: rollback: done finish merges
> [junit4] 1> DW 3 [2016-02-16T20:22:31.056Z; Thread-1221]: abort
> [junit4] 1> DW 3 [2016-02-16T20:22:31.057Z; Thread-1221]: done abort success=true
> [junit4] 1> IW 3 [2016-02-16T20:22:31.057Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.057Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1" [4 segments ; isCommit = false]
> [junit4] 1> IFD 3 [2016-02-16T20:22:31.057Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1>
> [junit4] 1> TEST: WriterThread iter=3
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.068Z; Thread-1221]: init: current segments file is "segments_4"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@11c721c
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.068Z; Thread-1221]: init: load commit "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.074Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1" [4 segments ; isCommit = false]
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.074Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IW 4 [2016-02-16T20:22:31.077Z; Thread-1221]: init: create=false
> [junit4] 1> IW 4 [2016-02-16T20:22:31.077Z; Thread-1221]:
> [junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
> [junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
> [junit4] 1> version=5.6.0
> [junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
> [junit4] 1> ramBufferSizeMB=16.0
> [junit4] 1> maxBufferedDocs=-1
> [junit4] 1> maxBufferedDeleteTerms=-1
> [junit4] 1> mergedSegmentWarmer=null
> [junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
> [junit4] 1> commit=null
> [junit4] 1> openMode=APPEND
> [junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
> [junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
> [junit4] 1> default WRITE_LOCK_TIMEOUT=0
> [junit4] 1> writeLockTimeout=0
> [junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
> [junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
> [junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@37e82f
> [junit4] 1> readerPooling=false
> [junit4] 1> perThreadHardLimitMB=1945
> [junit4] 1> useCompoundFile=true
> [junit4] 1> commitOnClose=true
> [junit4] 1> writer=org.apache.lucene.index.IndexWriter@6c6f01
> [junit4] 1>
> [junit4] 1> IW 4 [2016-02-16T20:22:31.078Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
> [junit4] 1> IW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: now flush at close
> [junit4] 1> IW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: start flush: applyAllDeletes=true
> [junit4] 1> IW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1
> [junit4] 1> DW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: startFullFlush
> [junit4] 1> DW 4 [2016-02-16T20:22:31.08Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
> [junit4] 1> DWFC 4 [2016-02-16T20:22:31.08Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_4, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
> [junit4] 1> DWPT 4 [2016-02-16T20:22:31.08Z; Thread-1221]: flush postings as segment _4 numDocs=1
> [junit4] 1> IW 4 [2016-02-16T20:22:31.082Z; Thread-1221]: 1 msec to write norms
> [junit4] 1> IW 4 [2016-02-16T20:22:31.082Z; Thread-1221]: 0 msec to write docValues
> [junit4] 1> IW 4 [2016-02-16T20:22:31.082Z; Thread-1221]: 0 msec to finish stored fields
> [junit4] 1> IW 4 [2016-02-16T20:22:31.085Z; Thread-1221]: 2 msec to write postings and finish vectors
> [junit4] 1> IW 4 [2016-02-16T20:22:31.086Z; Thread-1221]: 0 msec to write fieldInfos
> [junit4] 1> DWPT 4 [2016-02-16T20:22:31.086Z; Thread-1221]: new segment has 0 deleted docs
> [junit4] 1> DWPT 4 [2016-02-16T20:22:31.086Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
> [junit4] 1> DWPT 4 [2016-02-16T20:22:31.086Z; Thread-1221]: flushedFiles=[_4.fdx, _4.fnm, _4.nvd, _4_Lucene50_0.tip, _4.nvm, _4_Lucene50_0.tim, _4_Lucene50_0.pos, _4.fdt, _4_Lucene50_0.doc]
> [junit4] 1> DWPT 4 [2016-02-16T20:22:31.086Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> DWPT 4 [2016-02-16T20:22:31.087Z; Thread-1221]: flushed: segment=_4 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
> [junit4] 1> IW 4 [2016-02-16T20:22:31.087Z; Thread-1221]: create compound file
> [junit4] 1> DW 4 [2016-02-16T20:22:31.095Z; Thread-1221]: publishFlushedSegment seg-private updates=null
> [junit4] 1> IW 4 [2016-02-16T20:22:31.095Z; Thread-1221]: publishFlushedSegment
> [junit4] 1> IW 4 [2016-02-16T20:22:31.095Z; Thread-1221]: publish sets newSegment delGen=1 seg=_4(5.6.0):c1
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.095Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1" [5 segments ; isCommit = false]
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.095Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> DW 4 [2016-02-16T20:22:31.095Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.fdx"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.fnm"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.nvd"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4_Lucene50_0.tip"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.nvm"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4_Lucene50_0.tim"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4_Lucene50_0.pos"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4.fdt"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: will delete new file "_4_Lucene50_0.doc"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: delete "_4.fdx"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: delete "_4.fnm"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: unable to remove file "_4.fnm": java.io.IOException: cannot delete file: _4.fnm, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: delete "_4.nvd"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: unable to remove file "_4.nvd": java.io.IOException: cannot delete file: _4.nvd, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.096Z; Thread-1221]: delete "_4_Lucene50_0.tip"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: delete "_4.nvm"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: unable to remove file "_4.nvm": java.io.IOException: cannot delete file: _4.nvm, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: delete "_4_Lucene50_0.tim"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: delete "_4_Lucene50_0.pos"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.097Z; Thread-1221]: delete "_4.fdt"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.098Z; Thread-1221]: delete "_4_Lucene50_0.doc"
> [junit4] 1> IW 4 [2016-02-16T20:22:31.098Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 4 [2016-02-16T20:22:31.098Z; Thread-1221]: now apply all deletes for all segments maxDoc=5
> [junit4] 1> BD 4 [2016-02-16T20:22:31.098Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 4 [2016-02-16T20:22:31.098Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 4 [2016-02-16T20:22:31.098Z; Thread-1221]: prune sis=segments_4: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> TMP 4 [2016-02-16T20:22:31.098Z; Thread-1221]: findMerges: 5 segments
> [junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_3(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: seg=_4(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 4 [2016-02-16T20:22:31.099Z; Thread-1221]: allowedSegmentCount=1 vs count=5 (eligible count=5) tooBigCount=0
> [junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
> [junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: now merge
> [junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
> [junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
> [junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: now merge
> [junit4] 1> MS 4 [2016-02-16T20:22:31.1Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
> [junit4] 1> MS 4 [2016-02-16T20:22:31.101Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: waitForMerges
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: waitForMerges done
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: commit: start
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: commit: enter lock
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: commit: now prepare
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: prepareCommit: flush
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
> [junit4] 1> DW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: startFullFlush
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: now apply all deletes for all segments maxDoc=5
> [junit4] 1> BD 4 [2016-02-16T20:22:31.101Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 4 [2016-02-16T20:22:31.101Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 4 [2016-02-16T20:22:31.101Z; Thread-1221]: prune sis=segments_4: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> DW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: startCommit(): start
> [junit4] 1> IW 4 [2016-02-16T20:22:31.101Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 changeCount=3
> [junit4] 1> IW 4 [2016-02-16T20:22:31.105Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_5"
> [junit4] 1> IW 4 [2016-02-16T20:22:31.106Z; Thread-1221]: done all syncs: [_4.cfs, _2.si, _4.cfe, _3.si, _3.cfe, _1.si, _4.si, _0.cfe, _2.cfe, _2.cfs, _1.cfe, _0.si, _3.cfs, _1.cfs, _0.cfs]
> [junit4] 1> IW 4 [2016-02-16T20:22:31.106Z; Thread-1221]: commit: pendingCommit != null
> [junit4] 1> IW 4 [2016-02-16T20:22:31.107Z; Thread-1221]: commit: done writing segments file "segments_5"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1" [5 segments ; isCommit = true]
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: deleteCommits: now decRef commit "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: delete "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.107Z; Thread-1221]: delete "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
> [junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: commit: took 6.8 msec
> [junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: commit: done
> [junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: rollback
> [junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: all running merges have aborted
> [junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: rollback: done finish merges
> [junit4] 1> DW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: abort
> [junit4] 1> DW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: done abort success=true
> [junit4] 1> IW 4 [2016-02-16T20:22:31.108Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1" [5 segments ; isCommit = false]
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: delete "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.108Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: refresh: removing newly created unreferenced file "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: refresh: removing newly created unreferenced file "_4.nvd"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: refresh: removing newly created unreferenced file "_4.fnm"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: refresh: removing newly created unreferenced file "_4.nvm"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: delete "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: delete "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: delete "segments_4"
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.109Z; Thread-1221]: unable to remove file "segments_4": java.io.IOException: MockDirectoryWrapper: file "segments_4" is still open: cannot delete; Will re-try later.
> [junit4] 1> IFD 4 [2016-02-16T20:22:31.11Z; Thread-1221]: failed to remove commit point "segments_4"; skipping deletion of all other pending files
> [junit4] 1>
> [junit4] 1> TEST: WriterThread iter=4
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.12Z; Thread-1221]: init: current segments file is "segments_5"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@23dd2b
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.12Z; Thread-1221]: init: load commit "segments_4"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.136Z; Thread-1221]: init: load commit "segments_5"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: init: removing unreferenced file "_4.nvd"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: delete "_4.nvd"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: unable to remove file "_4.nvd": java.io.IOException: cannot delete file: _4.nvd, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: init: removing unreferenced file "_4.nvm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: delete "_4.nvm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: init: removing unreferenced file "_4.fnm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.14Z; Thread-1221]: delete "_4.fnm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.141Z; Thread-1221]: unable to remove file "_4.fnm": java.io.IOException: cannot delete file: _4.fnm, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.141Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1" [5 segments ; isCommit = false]
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.141Z; Thread-1221]: delete "_4.fnm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.141Z; Thread-1221]: delete "_4.nvd"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.142Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.142Z; Thread-1221]: deleteCommits: now decRef commit "segments_4"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.142Z; Thread-1221]: delete "segments_4"
> [junit4] 1> IW 5 [2016-02-16T20:22:31.148Z; Thread-1221]: init: create=false
> [junit4] 1> IW 5 [2016-02-16T20:22:31.148Z; Thread-1221]:
> [junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
> [junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
> [junit4] 1> version=5.6.0
> [junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
> [junit4] 1> ramBufferSizeMB=16.0
> [junit4] 1> maxBufferedDocs=-1
> [junit4] 1> maxBufferedDeleteTerms=-1
> [junit4] 1> mergedSegmentWarmer=null
> [junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
> [junit4] 1> commit=null
> [junit4] 1> openMode=APPEND
> [junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
> [junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
> [junit4] 1> default WRITE_LOCK_TIMEOUT=0
> [junit4] 1> writeLockTimeout=0
> [junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
> [junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
> [junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@1e2b62
> [junit4] 1> readerPooling=false
> [junit4] 1> perThreadHardLimitMB=1945
> [junit4] 1> useCompoundFile=true
> [junit4] 1> commitOnClose=true
> [junit4] 1> writer=org.apache.lucene.index.IndexWriter@b2590c
> [junit4] 1>
> [junit4] 1> IW 5 [2016-02-16T20:22:31.148Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
> [junit4] 1> IW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: now flush at close
> [junit4] 1> IW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: start flush: applyAllDeletes=true
> [junit4] 1> IW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1
> [junit4] 1> DW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: startFullFlush
> [junit4] 1> DW 5 [2016-02-16T20:22:31.15Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
> [junit4] 1> DWFC 5 [2016-02-16T20:22:31.15Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_5, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
> [junit4] 1> DWPT 5 [2016-02-16T20:22:31.15Z; Thread-1221]: flush postings as segment _5 numDocs=1
> [junit4] 1> IW 5 [2016-02-16T20:22:31.153Z; Thread-1221]: 2 msec to write norms
> [junit4] 1> IW 5 [2016-02-16T20:22:31.153Z; Thread-1221]: 0 msec to write docValues
> [junit4] 1> IW 5 [2016-02-16T20:22:31.154Z; Thread-1221]: 1 msec to finish stored fields
> [junit4] 1> IW 5 [2016-02-16T20:22:31.157Z; Thread-1221]: 2 msec to write postings and finish vectors
> [junit4] 1> IW 5 [2016-02-16T20:22:31.158Z; Thread-1221]: 0 msec to write fieldInfos
> [junit4] 1> DWPT 5 [2016-02-16T20:22:31.158Z; Thread-1221]: new segment has 0 deleted docs
> [junit4] 1> DWPT 5 [2016-02-16T20:22:31.158Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
> [junit4] 1> DWPT 5 [2016-02-16T20:22:31.158Z; Thread-1221]: flushedFiles=[_5.fnm, _5_Lucene50_0.tip, _5.nvm, _5_Lucene50_0.doc, _5.nvd, _5.fdt, _5.fdx, _5_Lucene50_0.pos, _5_Lucene50_0.tim]
> [junit4] 1> DWPT 5 [2016-02-16T20:22:31.158Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> DWPT 5 [2016-02-16T20:22:31.159Z; Thread-1221]: flushed: segment=_5 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
> [junit4] 1> IW 5 [2016-02-16T20:22:31.159Z; Thread-1221]: create compound file
> [junit4] 1> DW 5 [2016-02-16T20:22:31.189Z; Thread-1221]: publishFlushedSegment seg-private updates=null
> [junit4] 1> IW 5 [2016-02-16T20:22:31.189Z; Thread-1221]: publishFlushedSegment
> [junit4] 1> IW 5 [2016-02-16T20:22:31.189Z; Thread-1221]: publish sets newSegment delGen=1 seg=_5(5.6.0):c1
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.189Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1" [6 segments ; isCommit = false]
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.189Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> DW 5 [2016-02-16T20:22:31.19Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.fnm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5_Lucene50_0.tip"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.nvm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5_Lucene50_0.doc"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.nvd"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.fdt"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5.fdx"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5_Lucene50_0.pos"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: will delete new file "_5_Lucene50_0.tim"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: delete "_5.fnm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.19Z; Thread-1221]: delete "_5_Lucene50_0.tip"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: delete "_5.nvm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: unable to remove file "_5.nvm": java.io.IOException: cannot delete file: _5.nvm, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: delete "_5_Lucene50_0.doc"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: unable to remove file "_5_Lucene50_0.doc": java.io.IOException: cannot delete file: _5_Lucene50_0.doc, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.191Z; Thread-1221]: delete "_5.nvd"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.192Z; Thread-1221]: delete "_5.fdt"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.192Z; Thread-1221]: delete "_5_Lucene50_0.pos"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.192Z; Thread-1221]: delete "_5.fdx"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: delete "_5_Lucene50_0.tim"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: unable to remove file "_5_Lucene50_0.tim": java.io.IOException: cannot delete file: _5_Lucene50_0.tim, a virus scanner has it open; Will re-try later.
> [junit4] 1> IW 5 [2016-02-16T20:22:31.193Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 5 [2016-02-16T20:22:31.193Z; Thread-1221]: now apply all deletes for all segments maxDoc=6
> [junit4] 1> BD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 5 [2016-02-16T20:22:31.193Z; Thread-1221]: prune sis=segments_5: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> TMP 5 [2016-02-16T20:22:31.193Z; Thread-1221]: findMerges: 6 segments
> [junit4] 1> TMP 5 [2016-02-16T20:22:31.194Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_3(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_4(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: seg=_5(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 5 [2016-02-16T20:22:31.195Z; Thread-1221]: allowedSegmentCount=1 vs count=6 (eligible count=6) tooBigCount=0
> [junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
> [junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: now merge
> [junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
> [junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
> [junit4] 1> MS 5 [2016-02-16T20:22:31.196Z; Thread-1221]: now merge
> [junit4] 1> MS 5 [2016-02-16T20:22:31.197Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
> [junit4] 1> MS 5 [2016-02-16T20:22:31.197Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: waitForMerges
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: waitForMerges done
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: commit: start
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: commit: enter lock
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: commit: now prepare
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: prepareCommit: flush
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
> [junit4] 1> DW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: startFullFlush
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 5 [2016-02-16T20:22:31.197Z; Thread-1221]: now apply all deletes for all segments maxDoc=6
> [junit4] 1> BD 5 [2016-02-16T20:22:31.197Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 5 [2016-02-16T20:22:31.197Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 5 [2016-02-16T20:22:31.197Z; Thread-1221]: prune sis=segments_5: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> DW 5 [2016-02-16T20:22:31.198Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IW 5 [2016-02-16T20:22:31.198Z; Thread-1221]: startCommit(): start
> [junit4] 1> IW 5 [2016-02-16T20:22:31.198Z; Thread-1221]: startCommit index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 changeCount=3
> [junit4] 1> IW 5 [2016-02-16T20:22:31.207Z; Thread-1221]: startCommit: wrote pending segments file "pending_segments_6"
> [junit4] 1> IW 5 [2016-02-16T20:22:31.208Z; Thread-1221]: done all syncs: [_4.cfs, _2.si, _1.si, _3.si, _0.cfe, _5.cfe, _2.cfs, _3.cfs, _1.cfs, _0.cfs, _5.si, _4.cfe, _3.cfe, _4.si, _5.cfs, _2.cfe, _0.si, _1.cfe]
> [junit4] 1> IW 5 [2016-02-16T20:22:31.208Z; Thread-1221]: commit: pendingCommit != null
> [junit4] 1> IW 5 [2016-02-16T20:22:31.209Z; Thread-1221]: commit: done writing segments file "segments_6"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.209Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1" [6 segments ; isCommit = true]
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.209Z; Thread-1221]: deleteCommits: now decRef commit "segments_5"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.209Z; Thread-1221]: delete "segments_5"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.21Z; Thread-1221]: delete "_5.nvm"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.21Z; Thread-1221]: delete "_5_Lucene50_0.doc"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.21Z; Thread-1221]: delete "_5_Lucene50_0.tim"
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.211Z; Thread-1221]: 1 msec to checkpoint
> [junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: commit: took 13.5 msec
> [junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: commit: done
> [junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: rollback
> [junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: all running merges have aborted
> [junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: rollback: done finish merges
> [junit4] 1> DW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: abort
> [junit4] 1> DW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: done abort success=true
> [junit4] 1> IW 5 [2016-02-16T20:22:31.211Z; Thread-1221]: rollback: infos=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.211Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1" [6 segments ; isCommit = false]
> [junit4] 1> IFD 5 [2016-02-16T20:22:31.211Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1>
> [junit4] 1> TEST: WriterThread iter=5
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.244Z; Thread-1221]: init: current segments file is "segments_6"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1a57a74
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.244Z; Thread-1221]: init: load commit "segments_6"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.25Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1" [6 segments ; isCommit = false]
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.25Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IW 6 [2016-02-16T20:22:31.327Z; Thread-1221]: init: create=false
> [junit4] 1> IW 6 [2016-02-16T20:22:31.327Z; Thread-1221]:
> [junit4] 1> dir=MockDirectoryWrapper(MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@628653)
> [junit4] 1> index=_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
> [junit4] 1> version=5.6.0
> [junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
> [junit4] 1> ramBufferSizeMB=16.0
> [junit4] 1> maxBufferedDocs=-1
> [junit4] 1> maxBufferedDeleteTerms=-1
> [junit4] 1> mergedSegmentWarmer=null
> [junit4] 1> delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
> [junit4] 1> commit=null
> [junit4] 1> openMode=APPEND
> [junit4] 1> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
> [junit4] 1> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
> [junit4] 1> default WRITE_LOCK_TIMEOUT=0
> [junit4] 1> writeLockTimeout=0
> [junit4] 1> codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
> [junit4] 1> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
> [junit4] 1> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@1df36ce
> [junit4] 1> readerPooling=false
> [junit4] 1> perThreadHardLimitMB=1945
> [junit4] 1> useCompoundFile=true
> [junit4] 1> commitOnClose=true
> [junit4] 1> writer=org.apache.lucene.index.IndexWriter@18724e2
> [junit4] 1>
> [junit4] 1> IW 6 [2016-02-16T20:22:31.327Z; Thread-1221]: MMapDirectory.UNMAP_SUPPORTED=true
> [junit4] 1> IW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: now flush at close
> [junit4] 1> IW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: start flush: applyAllDeletes=true
> [junit4] 1> IW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: index before flush _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1
> [junit4] 1> DW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: startFullFlush
> [junit4] 1> DW 6 [2016-02-16T20:22:31.329Z; Thread-1221]: anyChanges? numDocsInRam=1 deletes=false hasTickets:false pendingChangesInFullFlush: false
> [junit4] 1> DWFC 6 [2016-02-16T20:22:31.329Z; Thread-1221]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_6, aborted=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
> [junit4] 1> DWPT 6 [2016-02-16T20:22:31.33Z; Thread-1221]: flush postings as segment _6 numDocs=1
> [junit4] 1> IW 6 [2016-02-16T20:22:31.341Z; Thread-1221]: 9 msec to write norms
> [junit4] 1> IW 6 [2016-02-16T20:22:31.341Z; Thread-1221]: 0 msec to write docValues
> [junit4] 1> IW 6 [2016-02-16T20:22:31.341Z; Thread-1221]: 0 msec to finish stored fields
> [junit4] 1> IW 6 [2016-02-16T20:22:31.345Z; Thread-1221]: 3 msec to write postings and finish vectors
> [junit4] 1> IW 6 [2016-02-16T20:22:31.345Z; Thread-1221]: 0 msec to write fieldInfos
> [junit4] 1> DWPT 6 [2016-02-16T20:22:31.345Z; Thread-1221]: new segment has 0 deleted docs
> [junit4] 1> DWPT 6 [2016-02-16T20:22:31.345Z; Thread-1221]: new segment has no vectors; norms; no docValues; prox; freqs
> [junit4] 1> DWPT 6 [2016-02-16T20:22:31.345Z; Thread-1221]: flushedFiles=[_6.fdx, _6.fnm, _6_Lucene50_0.pos, _6.nvd, _6_Lucene50_0.tim, _6.fdt, _6.nvm, _6_Lucene50_0.tip, _6_Lucene50_0.doc]
> [junit4] 1> DWPT 6 [2016-02-16T20:22:31.346Z; Thread-1221]: flushed codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}
> [junit4] 1> DWPT 6 [2016-02-16T20:22:31.346Z; Thread-1221]: flushed: segment=_6 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=1,140.997
> [junit4] 1> IW 6 [2016-02-16T20:22:31.346Z; Thread-1221]: create compound file
> [junit4] 1> DW 6 [2016-02-16T20:22:31.361Z; Thread-1221]: publishFlushedSegment seg-private updates=null
> [junit4] 1> IW 6 [2016-02-16T20:22:31.361Z; Thread-1221]: publishFlushedSegment
> [junit4] 1> IW 6 [2016-02-16T20:22:31.361Z; Thread-1221]: publish sets newSegment delGen=1 seg=_6(5.6.0):c1
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: now checkpoint "_0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 _6(5.6.0):c1" [7 segments ; isCommit = false]
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> DW 6 [2016-02-16T20:22:31.361Z; Thread-1221]: Thread-1221 finishFullFlush success=true
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: will delete new file "_6.fdx"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: will delete new file "_6.fnm"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.361Z; Thread-1221]: will delete new file "_6_Lucene50_0.pos"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6.nvd"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6_Lucene50_0.tim"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6.fdt"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6.nvm"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6_Lucene50_0.tip"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: will delete new file "_6_Lucene50_0.doc"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: delete "_6.fdx"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: unable to remove file "_6.fdx": java.io.IOException: cannot delete file: _6.fdx, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.362Z; Thread-1221]: delete "_6.fnm"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6_Lucene50_0.pos"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6_Lucene50_0.tim"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6.nvd"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: unable to remove file "_6.nvd": java.io.IOException: cannot delete file: _6.nvd, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6.fdt"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.363Z; Thread-1221]: delete "_6.nvm"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: unable to remove file "_6.nvm": java.io.IOException: cannot delete file: _6.nvm, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: delete "_6_Lucene50_0.tip"
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: unable to remove file "_6_Lucene50_0.tip": java.io.IOException: cannot delete file: _6_Lucene50_0.tip, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: delete "_6_Lucene50_0.doc"
> [junit4] 1> IW 6 [2016-02-16T20:22:31.364Z; Thread-1221]: apply all deletes during flush
> [junit4] 1> IW 6 [2016-02-16T20:22:31.364Z; Thread-1221]: now apply all deletes for all segments maxDoc=7
> [junit4] 1> BD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: applyDeletes: open segment readers took 0 msec
> [junit4] 1> BD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: applyDeletes: no segments; skipping
> [junit4] 1> BD 6 [2016-02-16T20:22:31.364Z; Thread-1221]: prune sis=segments_6: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 _6(5.6.0):c1 minGen=0 packetCount=0
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.364Z; Thread-1221]: findMerges: 7 segments
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_0(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_1(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_2(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_3(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_4(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_5(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: seg=_6(5.6.0):c1 size=0.001 MB [floored]
> [junit4] 1> TMP 6 [2016-02-16T20:22:31.366Z; Thread-1221]: allowedSegmentCount=1 vs count=7 (eligible count=7) tooBigCount=0
> [junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
> [junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: now merge
> [junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: index: _0(5.6.0):c1 _1(5.6.0):c1 _2(5.6.0):c1 _3(5.6.0):c1 _4(5.6.0):c1 _5(5.6.0):c1 _6(5.6.0):c1
> [junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: no more merges pending; now return
> [junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
> [junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-1221]: now merge
> [junit4] 1> MS 6 [2016-02-16T20:22:31.367Z; Thread-12
>
> [...truncated too long message...]
>
> ):c1
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: now checkpoint "_k(5.6.0):c19 _l(5.6.0):c1 _m(5.6.0):c1 _n(5.6.0):c1 _o(5.6.0):c1 _p(5.6.0):c1 _q(5.6.0):c1 _r(5.6.0):c1" [8 segments ; isCommit = false]
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: delete "segments_p"
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: delete "_r_Lucene50_0.pos"
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: unable to remove file "_r_Lucene50_0.pos": java.io.IOException: cannot delete file: _r_Lucene50_0.pos, a virus scanner has it open; Will re-try later.
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: 0 msec to checkpoint
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: refresh: removing newly created unreferenced file "_r_Lucene50_0.pos"
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: refresh: removing newly created unreferenced file "segments_p"
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: delete "segments_p"
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.917Z; Thread-1221]: unable to remove file "segments_p": java.nio.file.AccessDeniedException: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001\segments_p; Will re-try later.
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: failed to remove commit point "segments_p"; skipping deletion of all other pending files
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: delete "segments_p"
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: unable to remove file "segments_p": java.nio.file.AccessDeniedException: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001\segments_p; Will re-try later.
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: failed to remove commit point "segments_p"; skipping deletion of all other pending files
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: delete "segments_p"
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: unable to remove file "segments_p": java.nio.file.AccessDeniedException: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001\tempDir-001\segments_p; Will re-try later.
> [junit4] 1> IFD 25 [2016-02-16T20:22:32.918Z; Thread-1221]: failed to remove commit point "segments_p"; skipping deletion of all other pending files
> [junit4] 1>
> [junit4] 1> TEST: WriterThread iter=25
> [junit4] 1> IFD 26 [2016-02-16T20:22:32.934Z; Thread-1221]: init: current segments file is "segments_q"; deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@1402ba8
> [junit4] 1> IFD 26 [2016-02-16T20:22:32.934Z; Thread-1221]: init: load commit "segments_p"
> [junit4] 1> IW 26 [2016-02-16T20:22:32.934Z; Thread-1221]: init: hit exception on init; releasing write lock
> [junit4] 1>
> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestNativeFSLockFactory -Dtests.method=testStressLocks -Dtests.seed=9BA6F0917BCE9B90 -Dtests.slow=true -Dtests.locale=es-GT -Dtests.timezone=America/Lima -Dtests.asserts=true -Dtests.file.encoding=Cp1252
> [junit4] FAILURE 3.06s J1 | TestNativeFSLockFactory.testStressLocks <<<
> [junit4] > Throwable #1: java.lang.AssertionError: IndexWriter hit unexpected exceptions
> [junit4] > at __randomizedtesting.SeedInfo.seed([9BA6F0917BCE9B90:C597BE6C676253F6]:0)
> [junit4] > at org.apache.lucene.store.BaseLockFactoryTestCase.testStressLocks(BaseLockFactoryTestCase.java:174)
> [junit4] > at java.lang.Thread.run(Thread.java:745)
> [junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build\core\test\J1\temp\lucene.store.TestNativeFSLockFactory_9BA6F0917BCE9B90-001
> [junit4] 2> NOTE: test params are: codec=Asserting(Lucene54): {content=Lucene50(blocksize=128)}, docValues:{}, sim=DefaultSimilarity, locale=es-GT, timezone=America/Lima
> [junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_80 (32-bit)/cpus=3,threads=1,free=199458248,total=285425664
> [junit4] 2> NOTE: All tests run in this JVM: [TestWildcard, Test2BPositions, TestExceedMaxTermLength, TestPerFieldDocValuesFormat, TestFilteredQuery, TestTieredMergePolicy, TestFixedBitDocIdSet, TestNumericRangeQuery32, TestSpanExplanations, MultiCollectorTest, TestSloppyPhraseQuery, TestTragicIndexWriterDeadlock, TestMultiValuedNumericRangeQuery, TestDemoParallelLeafReader, TestMergeSchedulerExternal, TestIndexWriterForceMerge, TestElevationComparator, TestBlockPostingsFormat, TestBooleanQuery, TestInPlaceMergeSorter, TestReqExclBulkScorer, TestSearchAfter, TestIndexWriterOutOfFileDescriptors, TestBytesRefHash, TestRateLimiter, TestSentinelIntSet, TestMultiset, TestFastCompressionMode, TestPrefixFilter, TestPackedInts, TestUnicodeUtil, TestIndexWriterOnDiskFull, TestRoaringDocIdSet, TestDisjunctionMaxQuery, TestBooleanMinShouldMatch, TestIntroSorter, TestByteSlices, TestTopDocsCollector, TestRecyclingByteBlockAllocator, TestHighCompressionMode, TestFlex, TestIntsRef, TestPositionIncrement, Test2BSortedDocValuesOrds, TestPayloads, TestMultiCollector, TestToken, TestIndexWriterReader, TestAllFilesHaveCodecHeader, TestDocValuesRewriteMethod, TestCompiledAutomaton, TestNoMergePolicy, TestLevenshteinAutomata, TestMixedDocValuesUpdates, TestPrefixQuery, TestNot, TestSameTokenSamePosition, TestDirectMonotonic, TestPhrasePrefixQuery, TestPersistentSnapshotDeletionPolicy, TestLongPostings, Test2BPostings, TestStressIndexing, Test2BBinaryDocValues, TestCharFilter, TestDirectory, TestMultiLevelSkipList, TestBitDocIdSetBuilder, TestIndexCommit, TestBoostQuery, TestIndexWriterExceptions2, TestVirtualMethod, TestBooleanCoord, TestCustomSearcherSort, TestSimilarityProvider, TestSpansEnum, TestNRTCachingDirectory, TestDocumentsWriterStallControl, TestLongBitSet, TestRegexpRandom2, TestCheckIndex, Test2BPagedBytes, TestByteArrayDataInput, TestMatchNoDocsQuery, TestIndexReaderClose, TestFieldReuse, TestNearSpansOrdered, TestCrashCausesCorruptIndex, TestPostingsOffsets, TestSizeBoundedForceMerge, TestQueryCachingPolicy, TestSortedNumericSortField, TestNumericUtils, TestIndexWriterMergePolicy, TestDocValuesScoring, TestNumericRangeQuery64, TestStressAdvance, TestCachingWrapperFilter, TestForTooMuchCloning, TestFilterDirectory, TestNRTThreads, TestTermVectors, TestMatchAllDocsQuery, TestTimSorter, TestMergePolicyWrapper, TestFSTs, TestBytesStore, TestIndexWriterWithThreads, TestAddIndexes, TestIndexWriterExceptions, TestMultiMMap, TestSearcherManager, TestDeletionPolicy, TestBooleanOr, TestBasics, TestFlushByRamOrCountsPolicy, TestIndexWriterDelete, TestIndexWriterCommit, TestDirectoryReaderReopen, TestTimeLimitingCollector, TestConcurrentMergeScheduler, TestNeverDelete, TestMinimize, TestRollingUpdates, TestDocTermOrdsRewriteMethod, TestSnapshotDeletionPolicy, TestIndexWriterUnicode, TestNRTReaderWithThreads, TestConsistentFieldNumbers, TestSimpleExplanations, TestDirectoryReader, TestLockFactory, TestSegmentMerger, TestPhraseQuery, TestCollectionUtil, TestBagOfPositions, TestFixedBitSet, TestComplexExplanations, TestSegmentReader, TestFastDecompressionMode, TestFieldCacheRewriteMethod, TestPagedBytes, TestCrash, TestSegmentTermDocs, TestPerFieldPostingsFormat2, TestSort, TestDocValuesIndexing, TestHugeRamFile, TestCodecs, TestParallelLeafReader, TestStressNRT, TestIndexInput, TestForceMergeForever, TestSameScoresWithThreads, TestMultiFields, TestDocumentsWriterDeleteQueue, TestLiveFieldValues, TestDoc, TestExternalCodecs, TestSimpleExplanationsOfNonMatches, TestTermVectorsReader, TestPerSegmentDeletes, TestPrefixInBooleanQuery, TestPrefixCodedTerms, TestParallelReaderEmptyIndex, TestDocument, TestTopFieldCollector, TestFileSwitchDirectory, TestDateSort, TestSmallFloat, TestSearch, TestSpansAdvanced, TestDateFilter, TestCharsRef, TestBinaryDocument, TestAutomatonQueryUnicode, TestRamUsageEstimator, TestIsCurrent, TestIndexWriterLockRelease, TestDemo, TestIndexWriterOnJRECrash, TestCodecHoldsOpenFiles, TestScoreCachingWrappingScorer, TestIOUtils, TestBytesRefAttImpl, TestLucene50CompoundFormat, TestMergeRateLimiter, TestNRTReaderCleanup, TestOrdinalMap, TestReadOnlyIndex, TestStressDeletes, FuzzyTermOnShortTermsTest, TestConjunctionDISI, TestSortedSetSortField, TestBM25Similarity, TestFilterSpans, TestSpanCollection, TestSpanNearQuery, TestSpanOrQuery, TestNativeFSLockFactory]
> [junit4] Completed [401/421 (1!)] on J1 in 10.62s, 10 tests, 1 failure <<< FAILURES!
>
> [...truncated 72 lines...]
> BUILD FAILED
> C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\build.xml:750: The following error occurred while executing this line:
> C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\build.xml:694: The following error occurred while executing this line:
> C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\build.xml:59: The following error occurred while executing this line:
> C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\build.xml:50: The following error occurred while executing this line:
> C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\common-build.xml:1477: The following error occurred while executing this line:
> C:\Users\JenkinsSlave\workspace\Lucene-Solr-5.x-Windows\lucene\common-build.xml:1033: There were test failures: 421 suites (1 ignored), 3386 tests, 1 failure, 56 ignored (52 assumptions) [seed: 9BA6F0917BCE9B90]
>
> Total time: 6 minutes 18 seconds
> Build step 'Invoke Ant' marked build as failure
> Archiving artifacts
> [WARNINGS] Skipping publisher since build result is FAILURE
> Recording test results
> Email was triggered for: Failure - Any
> Sending email for trigger: Failure - Any
>
>
>
>
> ---------------------------------------------------------------------
> 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