[CI] InternalEngineTests.testLookupSeqNoByIdInLucene fails after prune ID merge policy

[henningandersen]

My PR build failed:

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+pull-request-1/193/testReport/org.elasticsearch.index.engine/InternalEngineTests/testLookupSeqNoByIdInLucene/

with:

java.lang.NullPointerException
	at __randomizedtesting.SeedInfo.seed([DDA237697902E2F7:858F7759E359C12]:0)
	at org.elasticsearch.index.engine.InternalEngineTests.lambda$testLookupSeqNoByIdInLucene$50(InternalEngineTests.java:4004)
	at org.elasticsearch.index.engine.InternalEngineTests.testLookupSeqNoByIdInLucene(InternalEngineTests.java:4031)

I can easily reproduce this with the seed DDA237697902E2F7. I cut down the test case to following (which indexes a doc, does a refresh, deletes the doc and then merges, loosing the ability to lookup the doc/seqno by ID):

    public void testLookupSeqNoByIdInLucene2() throws Exception {
        Settings.Builder settings = Settings.builder()
            .put(defaultSettings.getSettings())
            .put(IndexSettings.INDEX_SOFT_DELETES_SETTING.getKey(), true);
        final IndexMetaData indexMetaData = IndexMetaData.builder(defaultSettings.getIndexMetaData()).settings(settings).build();
        final IndexSettings indexSettings = IndexSettingsModule.newIndexSettings(indexMetaData);
        Map<String, Engine.Operation> latestOps = new HashMap<>(); // id -> latest seq_no
        try (Store store = createStore();
             InternalEngine engine = createEngine(config(indexSettings, store, createTempDir(), newMergePolicy(), null))) {
            final ParsedDocument doc = EngineTestCase.createParsedDoc("23", null);
            engine.index(new Engine.Index(EngineTestCase.newUid(doc), doc, 1, primaryTerm.get(),
                1, null, Engine.Operation.Origin.REPLICA, threadPool.relativeTimeInMillis(), -1, true, UNASSIGNED_SEQ_NO, 0L));
            engine.refresh("test");
            engine.delete(new Engine.Delete(doc.type(), doc.id(), EngineTestCase.newUid(doc), 3, primaryTerm.get(),
                1, null, Engine.Operation.Origin.REPLICA, threadPool.relativeTimeInMillis(), UNASSIGNED_SEQ_NO, 0L));
            try (Searcher searcher = engine.acquireSearcher("test", Engine.SearcherScope.INTERNAL)) {
                logger.info("before merge: " + searcher.reader().numDocs() + ", " + searcher.reader().maxDoc());
            }
            engine.forceMerge(true);
            try (Searcher searcher = engine.acquireSearcher("test", Engine.SearcherScope.INTERNAL)) {
                logger.info("after merge: " + searcher.reader().numDocs() + ", " + searcher.reader().maxDoc());
                DocIdAndSeqNo docIdAndSeqNo = VersionsAndSeqNoResolver.loadDocIdAndSeqNo(searcher.reader(), newUid("23"));
                assertNotNull(docIdAndSeqNo);
            }
        }
    }

I tried disabling the new PrunePostingsMergePolicy and this made the problem go away. As far as I can see, we do use this lookup by ID in InternalEngine.planIndexingAsNonPrimary and planDeletionAsNonPrimary in the case where the seqNo received is below local checkpoint.

I am unsure if this part can be removed now and simply always treat all ops below local checkpoint as stale? Therefore raising this issue to gather input.

[elasticmachine]

Pinging @elastic/es-distributed

[henningandersen]

ping @s1monw

[dnhatn]

To make LocalCheckpointTracker#contains work correctly, we started restoring the LocalCheckpointTracker from an index commit (in #34474). However, that change causes both FollowingEngine and InternalEngine wrongly to ignore deletes. We fixed the issue by using _id of soft-deletes to resolve the indexing strategy (#35230). Sadly, the new PrunePostingsMergePolicy (in #40741) would make the problem appear again. InternalEngine can incorrectly ignore deletes in following situation (copied from #35230).

1. Delete doc with seq=1 => engine will add a delete tombstone to Lucene

2. Flush a commit consisting of only the delete tombstone

3. Force merge the commit. The new commit has one document but without _id (new step comparing to Use soft-deleted docs to resolve strategy for engine operation #35230)

4. Index doc with seq=0 => engine will add that doc to Lucene but soft-deleted

5. Restart an engine with the merged commit (step 3); the engine will fill its LocalCheckpointTracker with the delete tombstone in the commit

6. Replay the local translog in reverse order: index#0 then delete#1

7. When process index#0, an engine will add it into Lucene as a live doc because no _id exists in the current commit (we have one document but its _id is pruned). The engine will advance the local checkpoint to 1 (seq#1 was restored from the commit - step 4).

8. When process delete#1, an engine will skip it because seq_no=1 is less than or equal to the local checkpoint.

We should have no document after recovering from translog, but here we have one.

[henningandersen]

I wonder if we can revert the work from #35230, since we now initialize

            maxSeqNoOfUpdatesOrDeletes = new AtomicLong(SequenceNumbers.max(localCheckpointTracker.getMaxSeqNo(), translog.getMaxSeqNo()));

(#41161)

According to comments here https://github.com/elastic/elasticsearch/blob/master/server/src/main/java/org/elasticsearch/index/engine/InternalEngine.java#L265 that initialization is an alternative solution to #35230? Sounds plausible, but I guess there could be something I am missing?

[jakelandis]

another failure on master: https://scans.gradle.com/s/6tkiqql4r3jra/tests/nfxodyych4uas-rx2ilcccihjwi?openStackTraces=WzBd

[henningandersen]

We discussed my suggestion above on another channel and came to the conclusion that doing this would violate the invariant that LocalCheckpointTracker is a cache of the checkpoint information in lucene.

Instead we can fix this during ID pruning by not pruning out IDs after local-checkpoint of safe commit.

[dnhatn]

I have muted this test on master and 7.x