[CI] CorruptedFileIT.testCorruptFileThenSnapshotAndRestore failure

[romseygeek]

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+multijob-unix-compatibility/os=sles/2435/console

After a file is corrupted, snapshot should throw an error, but it seems to succeed instead. Doesn't reproduce locally though.

consoleText.txt

[elasticmachine]

Pinging @elastic/es-distributed

[tlrx]

This test creates an index with 0 replica, merges disabled and a very high value for the flush translog size setting. Then it corrupts a file in a random primary shard (in this failure, it is _2.si), registers a repository and creates a snapshot.

When creating the snapshot, the test expects that the shard snapshot process loads the store metadata and then fails because one of the Lucene files is corrupted, failing the shard snapshot and marking the snapshot as PARTIAL.

In this test failure the snapshot completed as SUCCESS. I looked closely at it and I can't figure why it didn't fail when loading the store metadata. Of course it does not reproduce locally. The test correclty corrupted the file:

[INFO ][test                     ] Corrupting file --  flipping at position 68 from 0 to 1 file: _2.si
[INFO ][test                     ] Checksum before: [2483589937] after: [1016601414] checksum value after corruption: 2483589937] file: _2.si length: 387

I suspect a test bug, or maybe that the file was not part of the snapshot but it should have been. Merges are disabled and flushes are manually executed before corrupting the file.

I pushed 7915b5f to add more debug information, hopefully this error will appear again and we'll be able to grab the shard files and the snapshotted files.

[ywelsch]

@dnhatn With the changes that were made to CombinedDeletionPolicy, do you perhaps know if we can expect all unreferenced Lucene files to be cleaned up after a flush?

[dnhatn]

@ywelsch I have looked at the test.
If the latest value of the global checkpoint has not fsynced before a flush, we will have two commits; then if we corrupt some files which are referenced only by the previous commit, the snapshot of the latest commit will be SUCCESS instead of PARTIAL.

I will follow-up this test with @tlrx.

[ywelsch]

awesome!

[tlrx]

Good catch @ywelsch and @dnhatn. But what could make a file referenced by a commit point and not by the next one, when merges are disabled and the shard manually flushed?

[dnhatn]

@tlrx You're right. My assumption is not correct in this case.

[dnhatn]

@tlrx I will be taking care of this.

[dnhatn]

@tlrx and @ywelsch I've reproduced and have an explanation for this. This is possibly caused by LUCENE-8253

1. indexRandom(true, builders) not only add docs but also index/delete bogus docs.

[test][4] Index [fEPBemMBIyPePwGlvrH9]
 [test][4] Index [bogus_doc_ीनठफड़जऊa44]
[test][4] Index [oUPBemMBIyPePwGlvrH-]
[test][4] Delete [bogus_doc_ीनठफड़जऊa44]

2. With a special seed (A9D224BA3576B58B:E8899F47DB14C3CA), indexRandom might create a fully deleted segment in which all documents are deleted.

Segment _2(7.4.0):c1, files [_2.si, _2.cfe, _2.cfs], maxDocs=[1], numDocs=[0], delDocs=[1], seq#=[6] 

Previously, a fully deleted segment is kept around until the next commit, however since LUCENE-8253 it is dropped immediately. The problem is that its files, which are not referenced by any commit point, are not released but retained in IndexFileDeleter's lastFiles.

IFD's last files:  [_0.si, _3.si, _1.cfe, _1.si, _3_1.liv, _2.si, 
_0.cfs, _2.cfs, _3.cfe, _1.cfs, _0.cfe, _2.cfe, _3.cfs, _2_1.liv]

3. We then corrupt _2.cfe which belongs to the dropped segment.

Corrupting file --  flipping at position 197 from 0 to 1 file: _2.cfe

4. Taking snapshot should be ok because the last commit does not includes the corrupted file.

Loading store metadata using SnapshotIndexCommit{segments_3},
files: [_1.cfs, _0.cfe, _0.si, _3.si, _1.cfe, _1.si, _3_1.liv, _0.cfs, _3.cfs, _3.cfe, segments_3]

I opened LUCENE-8324. If @s1monw agrees to fix this in Lucene, we are good; otherwise we need to update the test.

[tlrx]

Thanks @dnhatn. I suspected something like that but I did not look deeply enough.