[OAK-5601] documentMk backgroundRead should handle missing journal entries

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 1.0.36, 1.2.23, 1.4.1, 1.6.0
• Fix Version/s: 1.0.37, 1.2.24, 1.4.14, 1.7.0, 1.6.1, 1.8.0
• Component/s: core
• Assignee: Stefan Egli
• Reporter: Stefan Egli
• Created: 08/Feb/17 09:50
• Updated: 22/Feb/17 09:52
• Resolved: 08/Feb/17 15:27

Description

The following exception has been encountered:

03.02.2017 02:39:08.068 *WARN* [DocumentNodeStore background read thread (1)] org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore Background operation failed: java.lang.IllegalStateException: M
issing external change for branch revision: b3-00000159f839b963-00000000
java.lang.IllegalStateException: Missing external change for branch revision: b3-00000159f839b963-00000000
        at org.apache.jackrabbit.oak.plugins.document.JournalEntry$3$1.computeNext(JournalEntry.java:321)
        at org.apache.jackrabbit.oak.plugins.document.JournalEntry$3$1.computeNext(JournalEntry.java:309)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138)
        at org.apache.jackrabbit.oak.plugins.document.JournalEntry.addTo(JournalEntry.java:287)
        at org.apache.jackrabbit.oak.plugins.document.JournalEntry.fillExternalChanges(JournalEntry.java:210)
        at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.backgroundRead(DocumentNodeStore.java:1813)
        at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.internalRunBackgroundReadOperations(DocumentNodeStore.java:1702)
        at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.runBackgroundReadOperations(DocumentNodeStore.java:1687)
        at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore$BackgroundReadOperation.execute(DocumentNodeStore.java:2633)
        at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore$NodeStoreTask.run(DocumentNodeStore.java:2592)
        at java.lang.Thread.run(Thread.java:745)

That revision b3-00000159f839b963-00000000 corresponds to 1485928249699ns == 2017-02-01T05:50:49+00:00, which means the revision that the backgroundRead is trying to read here is 21 hours old.

The default journal GC maxAge is 6 hours though.

When it tries to read an old revision that is already deleted it throws an IllegalStateException. That one is not caught properly, except in NodeStoreTask.run.

This means the backgroundRead has failed, with a warn, and will be retried 1 second later. Just that nothing has changed, the journal entry can still not be found, so the same warning is issued.

Resulting in the situation that the backgroundRead will never recover.

That IllegalStateException should be caught when calling fillExternalChanges, resulting in a fall-back to not reading from the journal but going the old route.

Issue Links

• is related to: OAK-5602 Avoid missing journal entries