[
https://issues.apache.org/jira/browse/OAK-2961?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14600724#comment-14600724
]
Amit Jain commented on OAK-2961:
--------------------------------
I think these warnings are fine. I debugged a little and these warnings seemed
to be caused by:
* A checkpoint of a successful async thread run being visible to 2 subsequent
threads.
* And one of these releasing the checkpoint after its successful run and the
2nd trying to read the checkpoint which has already been released.
Relevant logs:
{noformat}
10:51:40.025 DEBUG [oak-scheduled-executor-12] AsyncIndexUpdate.java:265
[async] Running background index task
10:51:40.030 INFO [oak-scheduled-executor-12] AsyncIndexUpdate.java:319 Marked
checkpointToRelease afterCheckpoint [r14e292a0ad4-1-4]
10:51:41.037 INFO [oak-scheduled-executor-12] AsyncIndexUpdate.java:432
[async] Reindexing completed for indexes: [/oak:index/asyncconflict*(0)] in
1.007 s
10:51:41.040 INFO [oak-scheduled-executor-12] AsyncIndexUpdate.java:334 Marked
checkpointToRelease beforeCheckpoint [r14e2929faff-0-1]
10:51:41.040 INFO [oak-scheduled-executor-12] AsyncIndexUpdate.java:351
[r14e2929faff-0-1] checkpoint to release
10:51:45.953 DEBUG [oak-scheduled-executor-19] AsyncIndexUpdate.java:265
[async] Running background index task
10:51:45.956 INFO [oak-scheduled-executor-19] AsyncIndexUpdate.java:319 Marked
checkpointToRelease afterCheckpoint [r14e292a1a05-1-3]
10:51:45.956 DEBUG [oak-scheduled-executor-19] AsyncIndexUpdate.java:221
[async] Releasing temporary checkpoint r14e2929faff-0-1: true
10:51:45.970 DEBUG [oak-scheduled-executor-19] AsyncIndexUpdate.java:447
[async] AsyncIndex update run completed in 14.37 ms. Indexed 0 nodes
10:51:45.971 INFO [oak-scheduled-executor-19] AsyncIndexUpdate.java:334 Marked
checkpointToRelease beforeCheckpoint [r14e292a0ad4-1-4]
10:51:46.042 DEBUG [oak-scheduled-executor-18] AsyncIndexUpdate.java:265
[async] Running background index task
10:51:46.042 WARN [oak-scheduled-executor-18] AsyncIndexUpdate.java:286
[async] Failed to retrieve previously indexed checkpoint r14e292a0ad4-1-4;
re-running the initial index update
10:51:46.043 INFO [oak-scheduled-executor-18] AsyncIndexUpdate.java:319 Marked
checkpointToRelease afterCheckpoint [r14e292a16af-0-4]
10:51:46.043 DEBUG [oak-scheduled-executor-18] AsyncIndexUpdate.java:221
[async] Releasing temporary checkpoint r14e2929faff-0-1: true
10:51:46.046 DEBUG [oak-scheduled-executor-18] AsyncIndexUpdate.java:221
[async] Releasing temporary checkpoint r14e292a0ad4-1-4: true
{noformat}
> Async index fails with OakState0001: Unresolved conflicts in /:async
> --------------------------------------------------------------------
>
> Key: OAK-2961
> URL: https://issues.apache.org/jira/browse/OAK-2961
> Project: Jackrabbit Oak
> Issue Type: Bug
> Components: mongomk, query
> Affects Versions: 1.2.2, 1.0.14, 1.4
> Reporter: Davide Giannella
> Assignee: Davide Giannella
> Labels: resilience
> Fix For: 1.2.3, 1.3.2
>
> Attachments: OAK-2961.patch
>
>
> When running on a mongo cluster, in case of high activity the async index
> could fail with the following exception.
> Reproduced with LucenePropertyIndex.
> {noformat}
> 10:55:13.069 [oak-scheduled-executor-5] WARN
> o.a.j.o.p.index.AsyncIndexUpdate - [async] The index update failed
> org.apache.jackrabbit.oak.api.CommitFailedException: OakState0001: Unresolved
> conflicts in /:async
> at
> org.apache.jackrabbit.oak.plugins.commit.ConflictValidator.failOnMergeConflict(ConflictValidator.java:84)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.commit.ConflictValidator.propertyAdded(ConflictValidator.java:54)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.spi.commit.EditorDiff.propertyAdded(EditorDiff.java:82)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:378)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:148)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:400)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.spi.commit.EditorDiff.process(EditorDiff.java:52)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.spi.commit.EditorHook.processCommit(EditorHook.java:55)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.spi.commit.CompositeHook.processCommit(CompositeHook.java:61)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch$InMemory.merge(DocumentNodeStoreBranch.java:528)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.merge0(DocumentNodeStoreBranch.java:219)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.merge(DocumentNodeStoreBranch.java:171)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentRootBuilder.merge(DocumentRootBuilder.java:158)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.merge(DocumentNodeStore.java:1466)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.mergeWithConcurrencyCheck(AsyncIndexUpdate.java:467)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.access$4(AsyncIndexUpdate.java:445)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate$AsyncUpdateCallback.<init>(AsyncIndexUpdate.java:201)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.updateIndex(AsyncIndexUpdate.java:372)
> ~[classes/:na]
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.run(AsyncIndexUpdate.java:320)
> ~[classes/:na]
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> [na:1.7.0_60]
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
> [na:1.7.0_60]
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
> [na:1.7.0_60]
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [na:1.7.0_60]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> [na:1.7.0_60]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> [na:1.7.0_60]
> at java.lang.Thread.run(Thread.java:745) [na:1.7.0_60]
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
