Hi Mike,

Thanks for figuring this out! I was just wondering if this is a new failure. So 
I think you changed something on this test?

In any case, your interpretation is correct. This is how it behaves. Maybe we 
should add this to Windows Directory, too.

Uwe

Am 30. August 2015 11:19:22 MESZ, schrieb Michael McCandless 
<[email protected]>:
>OK I dug a bit, and this behavior is maybe "by design" in Windows:
>
>Here's a java issue about it:
>
>    https://bugs.openjdk.java.net/browse/JDK-8029608
>
>Here's the "by design" explanation (though it's very old, I think it's
>likely the semantics of NTFS have not changed in this regard):
>
>    https://support.microsoft.com/en-us/kb/159199
>
>I didn't realize a file on NTFS could be in this "pending delete"
>state: I think this means the Files.delete call against the file
>succeeded (maybe?) in one thread, but then other threads still have
>the file open (in "shared access" mode).  This puts the file into
>"pending delete" state such that 1) it is still included in the dir
>listing, but 2) you cannot open it for read or write, nor delete it
>again (?).
>
>If this interpretation is correct, it easily explains this failure,
>and it might explain LUCENE-6684 if (maybe?) the original Files.delete
>call fails w/ an IOException.
>
>I'm going to disable these asserts for Windows: they are just causing
>noisy false test failures.
>
>Mike McCandless
>
>http://blog.mikemccandless.com
>
>
>On Sun, Aug 30, 2015 at 5:02 AM, Michael McCandless
><[email protected]> wrote:
>> This is a spooky (Windows) failure.
>>
>> This one thread was opening an IndexWriter, and IW had obtained the
>> write lock, successfully loaded the latest segments_3 commit point,
>> but listed the index directory and also saw segments_2 listed, and
>> tried to read it as well, but that hit AccessDeniedException.
>>
>> Why would get AccessDeniedExc trying to open a file for "read" on
>Windows?
>>
>> Another IW (from another thread) presumably had written segments_3,
>> tried to remove segments_2 but failed likely because an IndexReader
>> was at that moment opening that commit point ... but then segments_2
>> should simply remain in the directory and be readable.
>>
>>
>> Mike McCandless
>>
>> http://blog.mikemccandless.com
>>
>>
>> On Sun, Aug 30, 2015 at 2:44 AM, Policeman Jenkins Server
>> <[email protected]> wrote:
>>> Build:
>http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/5215/
>>> Java: 64bit/jdk1.8.0_60 -XX:+UseCompressedOops -XX:+UseG1GC
>>>
>>> 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([F9A229FCC6F79D63:A7936701DA5B5505]: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:173)
>>>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
>Method)
>>>         at
>sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>>>         at
>sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>>>         at java.lang.reflect.Method.invoke(Method.java:497)
>>>         at
>com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
>>>         at
>com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
>>>         at
>com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
>>>         at
>com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
>>>         at
>org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
>>>         at
>org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
>>>         at
>org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
>>>         at
>org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
>>>         at
>org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
>>>         at
>com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>>         at
>com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
>>>         at
>com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
>>>         at
>com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
>>>         at
>com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
>>>         at
>com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
>>>         at
>com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
>>>         at
>com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
>>>         at
>org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
>>>         at
>com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>>         at
>org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
>>>         at
>com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
>>>         at
>com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
>>>         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:54)
>>>         at
>org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
>>>         at
>org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
>>>         at
>org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
>>>         at
>com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>>         at
>com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
>>>         at java.lang.Thread.run(Thread.java:745)
>>>
>>>
>>>
>>>
>>> Build Log:
>>> [...truncated 1741 lines...]
>>>    [junit4] Suite: org.apache.lucene.store.TestNativeFSLockFactory
>>>    [junit4]   1> Stress Test Index Writer: creation hit unexpected
>exception: java.nio.file.AccessDeniedException:
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\core\test\J0\temp\lucene.store.TestNativeFSLockFactory_F9A229FCC6F79D63-001\tempDir-010\segments_2
>>>    [junit4]   1> java.nio.file.AccessDeniedException:
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\core\test\J0\temp\lucene.store.TestNativeFSLockFactory_F9A229FCC6F79D63-001\tempDir-010\segments_2
>>>    [junit4]   1>        at
>sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:83)
>>>    [junit4]   1>        at
>sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
>>>    [junit4]   1>        at
>sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:102)
>>>    [junit4]   1>        at
>sun.nio.fs.WindowsFileSystemProvider.newByteChannel(WindowsFileSystemProvider.java:230)
>>>    [junit4]   1>        at
>org.apache.lucene.mockfile.FilterFileSystemProvider.newByteChannel(FilterFileSystemProvider.java:213)
>>>    [junit4]   1>        at
>org.apache.lucene.mockfile.FilterFileSystemProvider.newByteChannel(FilterFileSystemProvider.java:213)
>>>    [junit4]   1>        at
>org.apache.lucene.mockfile.FilterFileSystemProvider.newByteChannel(FilterFileSystemProvider.java:213)
>>>    [junit4]   1>        at
>org.apache.lucene.mockfile.HandleTrackingFS.newByteChannel(HandleTrackingFS.java:241)
>>>    [junit4]   1>        at
>org.apache.lucene.mockfile.FilterFileSystemProvider.newByteChannel(FilterFileSystemProvider.java:213)
>>>    [junit4]   1>        at
>org.apache.lucene.mockfile.HandleTrackingFS.newByteChannel(HandleTrackingFS.java:241)
>>>    [junit4]   1>        at
>org.apache.lucene.mockfile.FilterFileSystemProvider.newByteChannel(FilterFileSystemProvider.java:213)
>>>    [junit4]   1>        at
>java.nio.file.Files.newByteChannel(Files.java:361)
>>>    [junit4]   1>        at
>java.nio.file.Files.newByteChannel(Files.java:407)
>>>    [junit4]   1>        at
>org.apache.lucene.store.SimpleFSDirectory.openInput(SimpleFSDirectory.java:76)
>>>    [junit4]   1>        at
>org.apache.lucene.store.Directory.openChecksumInput(Directory.java:109)
>>>    [junit4]   1>        at
>org.apache.lucene.store.RawDirectoryWrapper.openChecksumInput(RawDirectoryWrapper.java:42)
>>>    [junit4]   1>        at
>org.apache.lucene.index.SegmentInfos.readCommit(SegmentInfos.java:282)
>>>    [junit4]   1>        at
>org.apache.lucene.index.IndexFileDeleter.<init>(IndexFileDeleter.java:168)
>>>    [junit4]   1>        at
>org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:935)
>>>    [junit4]   1>        at
>org.apache.lucene.store.BaseLockFactoryTestCase$WriterThread.run(BaseLockFactoryTestCase.java:223)
>>>    [junit4]   1> IFD 102 [2015-08-30T06:44:32.052Z; Thread-892]:
>init: current segments file is "segments_3";
>deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@369d6cf
>>>    [junit4]   1> IFD 102 [2015-08-30T06:44:32.052Z; Thread-892]:
>init: load commit "segments_2"
>>>    [junit4]   1> IW 102 [2015-08-30T06:44:32.052Z; Thread-892]:
>init: hit exception on init; releasing write lock
>>>    [junit4]   1>
>>>    [junit4]   2> NOTE: reproduce with: ant test 
>-Dtestcase=TestNativeFSLockFactory -Dtests.method=testStressLocks
>-Dtests.seed=F9A229FCC6F79D63 -Dtests.slow=true -Dtests.locale=en_ZA
>-Dtests.timezone=Australia/Tasmania -Dtests.asserts=true
>-Dtests.file.encoding=UTF-8
>>>    [junit4] FAILURE 1.12s J0 |
>TestNativeFSLockFactory.testStressLocks <<<
>>>    [junit4]    > Throwable #1: java.lang.AssertionError: IndexWriter
>hit unexpected exceptions
>>>    [junit4]    >        at
>__randomizedtesting.SeedInfo.seed([F9A229FCC6F79D63:A7936701DA5B5505]:0)
>>>    [junit4]    >        at
>org.apache.lucene.store.BaseLockFactoryTestCase.testStressLocks(BaseLockFactoryTestCase.java:173)
>>>    [junit4]    >        at java.lang.Thread.run(Thread.java:745)
>>>    [junit4]   2> NOTE: leaving temporary files on disk at:
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\core\test\J0\temp\lucene.store.TestNativeFSLockFactory_F9A229FCC6F79D63-001
>>>    [junit4]   2> NOTE: test params are: codec=CheapBastard,
>sim=DefaultSimilarity, locale=en_ZA, timezone=Australia/Tasmania
>>>    [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation
>1.8.0_60 (64-bit)/cpus=3,threads=1,free=206572952,total=536870912
>>>    [junit4]   2> NOTE: All tests run in this JVM:
>[TestMergedIterator, TestDirectoryReaderReopen, TestIndexWriterMaxDocs,
>TestIndexWriterOutOfFileDescriptors, TestConcurrentMergeScheduler,
>TestIndexWriterOnDiskFull, TestTimSorterWorstCase, TestOperations,
>TestOfflineSorter, TestTopFieldCollector, TestLazyProxSkipping,
>TestCompiledAutomaton, TestParallelCompositeReader,
>LimitedFiniteStringsIteratorTest, TestIndexWriterExceptions2,
>TestWindowsMMap, TestHugeRamFile, TestNumericTokenStream,
>TestDeletionPolicy, TestIndexWriterDelete, TestByteBlockPool,
>TestMinShouldMatch2, TestRateLimiter, TestScoreCachingWrappingScorer,
>TestLucene50TermVectorsFormat, TestIndexWriterFromReader,
>TestTopDocsCollector, TestReaderClosed, TestSparseFixedBitDocIdSet,
>TestMaxPosition, TestComplexExplanations, TestDocValuesRewriteMethod,
>TestAllFilesHaveChecksumFooter, TestPerFieldPostingsFormat,
>TestSpanContainQuery, TestDirectory, TestCustomNorms,
>TestLucene50CompoundFormat, TestPayloadTermQuery, TestNorms, TestFlex,
>TestLucene50DocValuesFormat, TestIndexWriterExceptions,
>TestMutableValues, TestDocument, TestTryDelete, TestCheckIndex,
>TestQueryBuilder, TestSloppyPhraseQuery2, TestBlockPostingsFormat3,
>TestFieldReuse, TestMaxTermFrequency, TestOrdinalMap,
>TestLucene53NormsFormat, TestSloppyMath, TestSortedSetSelector,
>TestShardSearching, TestDocsAndPositions, TestNoMergeScheduler,
>TestLRUQueryCache, TestTermRangeQuery, TestSpanSearchEquivalence,
>TestRegexpQuery, TestMergeRateLimiter, TestAttributeSource,
>TestStressDeletes, TestDisjunctionMaxQuery, TestParallelTermEnum,
>TestSimpleFSLockFactory, TestBytesRefHash, TestMultiPhraseQuery,
>TestSpanMultiTermQueryWrapper, TestLockFactory,
>TestIndexWriterLockRelease, TestStringHelper, TestPositionIncrement,
>TestPerSegmentDeletes, TestSpanNearQuery, Test2BTerms,
>TestUniqueTermCount, TestFilterLeafReader, TestCollectionUtil,
>TestPayloadScoreQuery, TestTerm, TestIntBlockPool,
>TestBufferedChecksum, TestFuzzyQuery, TestAutomatonQuery,
>TestDefaultSimilarity, TestSegmentTermDocs, TestDateTools,
>TestIndexWriterForceMerge, TestControlledRealTimeReopenThread,
>TestIndexWriterWithThreads, TestNotDocIdSet,
>TestIndexWriterThreadsToSegments, TestRollback, TestVirtualMethod,
>TestFSTs, TestTermsEnum, TestNRTCachingDirectory,
>TestIndexWriterNRTIsCurrent, TestFieldCacheRewriteMethod,
>TestTransactions, TestPerFieldPostingsFormat2, TestCustomSearcherSort,
>TestTermsEnum2, TestNumericUtils, TestUTF32ToUTF8,
>TestFastCompressionMode, TestRAMDirectory, TestTermVectorsWriter,
>TestCharTermAttributeImpl, TestOmitPositions, TestStressNRT,
>TestSameScoresWithThreads, TestDocumentsWriterDeleteQueue,
>TestCrashCausesCorruptIndex, TestMultiTermConstantScore,
>TestLiveFieldValues, TestWildcard, TestFieldMaskingSpanQuery,
>TestSpansAdvanced2, TestUnicodeUtil, TestParallelReaderEmptyIndex,
>TestIndexableField, TestSentinelIntSet,
>TestBooleanQueryVisitSubscorers, TestSizeBoundedForceMerge,
>TestDocIdSet, TestBinaryTerms, TestRecyclingIntBlockAllocator,
>TestSimilarity, TestSetOnce, TestFilterIterator, TestCharsRef,
>TestSameTokenSamePosition, TestCachingCollector,
>TestAutomatonQueryUnicode, TestBooleanScorer, TestIsCurrent,
>TestNamedSPILoader, TestTwoPhaseCommitTool, TestIndexWriterOnJRECrash,
>TestCodecHoldsOpenFiles, TestDocBoost, TestIntsRef, TestTermdocPerf,
>Test2BPostingsBytes, TestNewestSegment, Test2BBinaryDocValues,
>TestReusableStringReader, TestLucene50FieldInfoFormat,
>TestLucene50SegmentInfoFormat, TestLucene50StoredFieldsFormat,
>Test2BSortedDocValuesFixedSorted, Test2BSortedDocValuesOrds,
>TestBinaryDocValuesUpdates, TestDocValues, TestExceedMaxTermLength,
>TestExitableDirectoryReader, TestIndexWriterDeleteByQuery,
>TestInfoStream, TestLogMergePolicy, TestNumericDocValuesUpdates,
>TestReaderWrapperDVTypeCheck, TestTermVectors, TestTerms,
>TestTragicIndexWriterDeadlock, FuzzyTermOnShortTermsTest,
>TestApproximationSearchEquivalence, TestBooleanCoord,
>TestCachingWrapperQuery, TestConjunctionDISI, TestEarlyTermination,
>TestFilterCachingPolicy, TestSortRescorer, TestSortedSetSortField,
>TestFilterSpans, TestSpanNotQuery, TestFilterDirectory,
>TestNativeFSLockFactory]
>>>    [junit4] Completed [386/401] on J0 in 11.89s, 10 tests, 1 failure
><<< FAILURES!
>>>
>>> [...truncated 59 lines...]
>>> BUILD FAILED
>>>
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:775:
>The following error occurred while executing this line:
>>>
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:719:
>The following error occurred while executing this line:
>>>
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:59:
>The following error occurred while executing this line:
>>>
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build.xml:50:
>The following error occurred while executing this line:
>>>
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1432:
>The following error occurred while executing this line:
>>>
>C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:987:
>There were test failures: 401 suites, 3227 tests, 1 failure, 56 ignored
>(52 assumptions)
>>>
>>> Total time: 5 minutes 54 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: [email protected]
>>> For additional commands, e-mail: [email protected]
>
>---------------------------------------------------------------------
>To unsubscribe, e-mail: [email protected]
>For additional commands, e-mail: [email protected]

--
Uwe Schindler
H.-H.-Meier-Allee 63, 28213 Bremen
http://www.thetaphi.de

Reply via email to