[jira] [Created] (OAK-10826) Misleading warning about missing checkpoint

["Daniel Iancu (Jira)" <ji...@apache.org>]

Daniel Iancu created OAK-10826:
----------------------------------

             Summary: Misleading warning about missing checkpoint
                 Key: OAK-10826
                 URL: https://issues.apache.org/jira/browse/OAK-10826
             Project: Jackrabbit Oak
          Issue Type: Bug
          Components: store-composite
            Reporter: Daniel Iancu


The CompositeNodeStore logs a WARN message when {{NodeStore.checkpointInfo()}} is called with a reference to a checkpoint that does not exist. The contract says, in this case the implementation will return an empty map. The CompositeNodeStore behaves as specified, but the log message indicates something is wrong.

One occasion when this can happen is the cleanup of unused checkpoints. See stack trace of the exception logged by the CompositeNodeStore. The cleanup first lists the checkpoints and then gets the info for each of the checkpoints. It may happen that one of the checkpoints is released in the meantime and {{NodeStore.checkpointInfo()}} is called for a checkpoint that does not exist anymore. The cleanup code is is working fine in this case, but the warning is misleading.

{noformat}
19.09.2019 05:21:00.686 *WARN* [sling-oak-2-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-async] org.apache.jackrabbit.oak.composite.CompositeNodeStore Checkpoint r16d47f757cd-0-2 doesn't exist. Debug info:
Mount: [default]
Checkpoints:
 - r16d47f76b54-1-2: {composite.checkpoint.expires=1655270460244, creator=AsyncIndexUpdate, composite.checkpoint.created=1568870460244, created=2019-09-19T05:21:00.244Z, name=async, thread=sling-oak-2-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-async}
 - r16d47f76b54-0-2: {composite.checkpoint.expires=1655270460244, creator=AsyncIndexUpdate, composite.checkpoint.created=1568870460244, created=2019-09-19T05:21:00.244Z, name=fulltext-async, thread=sling-oak-1-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-fulltext-async}
/:async node: {fulltext-async = r16d47f76b54-0-2, fulltext-async-LastIndexedTo = 2019-09-19T05:21:00.244Z, async-temp: [...], fulltext-async-temp: [...], async = r16d47f76b54-1-2, async-LastIndexedTo = 2019-09-19T05:21:00.244Z}
Mount: libs
Checkpoints:
 - f1d323f2-8a6f-4369-bf5f-608862f8b3b9: {creator=AsyncIndexUpdate, created=2019-09-18T18:56:41.352Z, name=async, thread=sling-oak-5-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-async}
 - 6ae116de-3eb0-4041-b4d1-f629e26d669c: {creator=AsyncIndexUpdate, created=2019-09-18T18:56:41.353Z, name=fulltext-async, thread=sling-oak-1-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-fulltext-async}
/:async node: {async-temp: [...], fulltext-async-temp: [...], fulltext-async-LastIndexedTo = 2019-09-18T18:56:41.353Z, async = f1d323f2-8a6f-4369-bf5f-608862f8b3b9, fulltext-async = 6ae116de-3eb0-4041-b4d1-f629e26d669c, async-LastIndexedTo = 2019-09-18T18:56:41.352Z}

java.lang.Exception: null
	at org.apache.jackrabbit.oak.composite.CompositeNodeStore.checkpointInfo(CompositeNodeStore.java:246) [org.apache.jackrabbit.oak-store-composite:1.16.0.R1867074]
	at org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.cleanUpCheckpoints(AsyncIndexUpdate.java:675) [org.apache.jackrabbit.oak-core:1.16.0.R1867074]
	at org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.maybeCleanUpCheckpoints(AsyncIndexUpdate.java:646) [org.apache.jackrabbit.oak-core:1.16.0.R1867074]
	at org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.runWhenPermitted(AsyncIndexUpdate.java:607) [org.apache.jackrabbit.oak-core:1.16.0.R1867074]
	at org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.run(AsyncIndexUpdate.java:432) [org.apache.jackrabbit.oak-core:1.16.0.R1867074]
	at org.apache.sling.commons.scheduler.impl.QuartzJobExecutor.execute(QuartzJobExecutor.java:347) [org.apache.sling.commons.scheduler:2.7.4]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202) [org.apache.sling.commons.scheduler:2.7.4]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
{noformat}



--
This message was sent by Atlassian Jira
(v8.20.10#820010)