[
https://issues.apache.org/jira/browse/OAK-2815?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Thomas Mueller updated OAK-2815:
--------------------------------
Labels: (was: docs-impacting)
> Persistent cache may block commit
> ---------------------------------
>
> Key: OAK-2815
> URL: https://issues.apache.org/jira/browse/OAK-2815
> Project: Jackrabbit Oak
> Issue Type: Bug
> Affects Versions: 1.2
> Reporter: Marcel Reutegger
> Assignee: Thomas Mueller
> Fix For: 1.2.2, 1.3.0, 1.0.14
>
> Attachments: OAK-2815.patch
>
>
> The persistent cache may block a commit for a rather long time if the
> generation is switched during the commit. The default configuration tells the
> persistent cache to compact the store when it is closed. This is exactly what
> happens when a generation is switched.
> I think it would be best to disable compaction.
> I was able to reproduce it with the {{ContinuousRevisionGCTest}} in oak-run
> with {{-DgarbageRatio=0.9}}, but it probably also happens with the default
> garbage ratio of 0.5.
> Once the MVStore reaches 1GB, the console will show something like this:
> {noformat}
> Performed RevisionGC in 6.331 s
> (VersionGCStats{ignoredGCDueToCheckPoint=false, deletedDocGCCount=54054,
> splitDocGCCount=0, intermediateSplitDocGCCount=0,
> timeToCollectDeletedDocs=622.8 ms, timeTakenToDeleteDocs=5.708 s})
> .................
> Performed RevisionGC in 9.232 s
> (VersionGCStats{ignoredGCDueToCheckPoint=false, deletedDocGCCount=26026,
> splitDocGCCount=0, intermediateSplitDocGCCount=0,
> timeToCollectDeletedDocs=6.549 s, timeTakenToDeleteDocs=2.682 s})
> Performed RevisionGC in 1.269 s
> (VersionGCStats{ignoredGCDueToCheckPoint=false, deletedDocGCCount=12012,
> splitDocGCCount=0, intermediateSplitDocGCCount=0,
> timeToCollectDeletedDocs=133.5 ms, timeTakenToDeleteDocs=1.134 s})
> Performed RevisionGC in 20.49 ms
> (VersionGCStats{ignoredGCDueToCheckPoint=false, deletedDocGCCount=0,
> splitDocGCCount=0, intermediateSplitDocGCCount=0,
> timeToCollectDeletedDocs=19.50 ms, timeTakenToDeleteDocs=0.000 ns})
> .15:19:16.682 [DocumentNodeStore background update thread] INFO
> o.a.j.o.p.document.DocumentNodeStore - Background operations stats (clean:0,
> split:0, lock:35581, write:1, num:5)
> ............
> Performed RevisionGC in 8.449 s
> (VersionGCStats{ignoredGCDueToCheckPoint=false, deletedDocGCCount=2002,
> splitDocGCCount=0, intermediateSplitDocGCCount=0,
> timeToCollectDeletedDocs=8.276 s, timeTakenToDeleteDocs=171.7 ms})
> {noformat}
> The background update thread had to wait 35 seconds for the
> backgroundOperations lock, which was held by the committing thread:
> {noformat}
> "Thread-2" prio=5 tid=0x00007f986b9a7800 nid=0x6803 runnable
> [0x0000000112780000]
> java.lang.Thread.State: RUNNABLE
> at org.h2.compress.CompressLZF.compress(CompressLZF.java:239)
> at org.h2.mvstore.Page.write(Page.java:754)
> at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:816)
> at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:822)
> at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:822)
> at org.h2.mvstore.MVStore.storeNowTry(MVStore.java:1065)
> at org.h2.mvstore.MVStore.storeNow(MVStore.java:981)
> at org.h2.mvstore.MVStore.commitAndSave(MVStore.java:970)
> - locked <0x00000007e15cccf0> (a org.h2.mvstore.MVStore)
> at org.h2.mvstore.MVStore.beforeWrite(MVStore.java:2084)
> at org.h2.mvstore.MVMap.beforeWrite(MVMap.java:1046)
> at org.h2.mvstore.MVMap.copy(MVMap.java:1231)
> at org.h2.mvstore.MVMap.copy(MVMap.java:1248)
> at org.h2.mvstore.MVMap.copy(MVMap.java:1248)
> at org.h2.mvstore.MVMap.copyFrom(MVMap.java:1218)
> at org.h2.mvstore.MVStoreTool.compact(MVStoreTool.java:493)
> at org.h2.mvstore.MVStoreTool.compact(MVStoreTool.java:458)
> at org.h2.mvstore.MVStoreTool.compact(MVStoreTool.java:404)
> at
> org.apache.jackrabbit.oak.plugins.document.persistentCache.PersistentCache$1.closeStore(PersistentCache.java:235)
> - locked <0x00000007c0c82760> (a
> org.apache.jackrabbit.oak.plugins.document.persistentCache.PersistentCache$1)
> at
> org.apache.jackrabbit.oak.plugins.document.persistentCache.PersistentCache.switchGenerationIfNeeded(PersistentCache.java:372)
> - locked <0x00000007c03a6c00> (a
> org.apache.jackrabbit.oak.plugins.document.persistentCache.PersistentCache)
> at
> org.apache.jackrabbit.oak.plugins.document.persistentCache.NodeCache.write(NodeCache.java:85)
> at
> org.apache.jackrabbit.oak.plugins.document.persistentCache.NodeCache.put(NodeCache.java:130)
> at
> org.apache.jackrabbit.oak.plugins.document.LocalDiffCache$1.done(LocalDiffCache.java:98)
> at
> org.apache.jackrabbit.oak.plugins.document.Commit.applyToCache(Commit.java:602)
> at
> org.apache.jackrabbit.oak.plugins.document.CommitQueue.afterTrunkCommit(CommitQueue.java:127)
> - locked <0x00000007c03a46f0> (a
> org.apache.jackrabbit.oak.plugins.document.CommitQueue)
> at
> org.apache.jackrabbit.oak.plugins.document.CommitQueue.done(CommitQueue.java:83)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.done(DocumentNodeStore.java:644)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.persist(DocumentNodeStoreBranch.java:338)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.persist(DocumentNodeStoreBranch.java:304)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.access$200(DocumentNodeStoreBranch.java:52)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch$InMemory.merge(DocumentNodeStoreBranch.java:541)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.merge0(DocumentNodeStoreBranch.java:230)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.merge(DocumentNodeStoreBranch.java:171)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentRootBuilder.merge(DocumentRootBuilder.java:158)
> at
> org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.merge(DocumentNodeStore.java:1490)
> at
> org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:247)
> at
> org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.commit(SessionDelegate.java:341)
> at
> org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.save(SessionDelegate.java:487)
> at
> org.apache.jackrabbit.oak.jcr.session.SessionImpl$8.performVoid(SessionImpl.java:424)
> at
> org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.performVoid(SessionDelegate.java:268)
> at
> org.apache.jackrabbit.oak.jcr.session.SessionImpl.save(SessionImpl.java:421)
> at
> org.apache.jackrabbit.oak.ContinuousRevisionGCTest$Writer.run(ContinuousRevisionGCTest.java:72)
> at java.lang.Thread.run(Thread.java:745)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
