[jira] [Commented] (OAK-8067) Measure fsync (called when closing the NRT index) and try to reduce disk I/O
[ https://issues.apache.org/jira/browse/OAK-8067?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16774863#comment-16774863 ] Thomas Mueller commented on OAK-8067: - http://svn.apache.org/r1854115 (trunk) FYI [~catholicon] > Measure fsync (called when closing the NRT index) and try to reduce disk I/O > > > Key: OAK-8067 > URL: https://issues.apache.org/jira/browse/OAK-8067 > Project: Jackrabbit Oak > Issue Type: Improvement > Components: lucene >Reporter: Thomas Mueller >Assignee: Thomas Mueller >Priority: Major > > We have seen the following stack trace, and saw that fsync was seemingly very > slow on the system. > Two issues: (1) fsync seems to be very slow here (2) fsync is called while > holding a lock. > (2) should be resolved by lazy-loading indexes. > {noformat} > "oak-lucene-22" daemon prio=1 tid=0x6b1 nid=0x runnable >java.lang.Thread.State: RUNNABLE > atjava.io.FileDescriptor.sync(Native Method) > at org.apache.lucene.store.FSDirectory.fsync(FSDirectory.java:505) > at org.apache.lucene.store.FSDirectory.sync(FSDirectory.java:307) > at > org.apache.lucene.store.NRTCachingDirectory.sync(NRTCachingDirectory.java:219) > at > org.apache.lucene.index.IndexWriter.startCommit(IndexWriter.java:4489) > at > org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2953) > - locked <0x20595abf> (a java.lang.Object) > at > org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3049) > - locked <0x20595abf> (a java.lang.Object) > at > org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1041) > at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:932) > - locked <0x20595abf> (a java.lang.Object) > at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:894) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndex.close(NRTIndex.java:206) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory.closeLast(NRTIndexFactory.java:133) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory.createIndex(NRTIndexFactory.java:89) > - locked <0x85f9b65> (a > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory) > at > org.apache.jackrabbit.oak.plugins.index.lucene.LuceneIndexNodeManager.open(LuceneIndexNodeManager.java:73) > at > org.apache.jackrabbit.oak.plugins.index.lucene.IndexTracker$1.leave(IndexTracker.java:154) > at > org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:152) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$WrappingDiff.childNodeChanged(CompositeNodeState.java:309) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$ChildrenDiffFilter.childNodeChanged(CompositeNodeState.java:256) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compareExisting(JsopNodeStateDiffer.java:100) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.access$000(JsopNodeStateDiffer.java:27) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer$1.childNodeChanged(JsopNodeStateDiffer.java:65) > at > org.apache.jackrabbit.oak.plugins.document.DiffCache.parseJsopDiff(DiffCache.java:118) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compare(JsopNodeStateDiffer.java:51) > at > org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.compare(DocumentNodeStore.java:1766) > at > org.apache.jackrabbit.oak.plugins.document.AbstractDocumentNodeState.compareAgainstBaseState(AbstractDocumentNodeState.java:113) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState.compareAgainstBaseState(CompositeNodeState.java:163) > at > org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$WrappingDiff.childNodeChanged(CompositeNodeState.java:309) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$ChildrenDiffFilter.childNodeChanged(CompositeNodeState.java:256) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compareExisting(JsopNodeStateDiffer.java:100) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.access$000(JsopNodeStateDiffer.java:27) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer$1.childNodeChanged(JsopNodeStateDiffer.java:65) > at > org.apache.jackrabbit.oak.plugins.document.DiffCache.parseJsopDiff(DiffCache.java:118) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer
[jira] [Commented] (OAK-8067) Measure fsync (called when closing the NRT index)
[ https://issues.apache.org/jira/browse/OAK-8067?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16774850#comment-16774850 ] Thomas Mueller commented on OAK-8067: - As we have "FileUtils.deleteQuietly(indexDir)" right after closing, I think it should be fine to also call "deleteAll()" before closing. deleteQuietly will just try to delete, and errors to delete are silently ignored. So possibly it's not always deleted. So, I'm not sure about concurrent usage of the index, what happens in case of power failure, or when the index isn't removed. I will add "deleteAll" by default, but use a different setting that allows to disable just that. > Measure fsync (called when closing the NRT index) > - > > Key: OAK-8067 > URL: https://issues.apache.org/jira/browse/OAK-8067 > Project: Jackrabbit Oak > Issue Type: Improvement > Components: lucene >Reporter: Thomas Mueller >Assignee: Thomas Mueller >Priority: Major > > We have seen the following stack trace, and saw that fsync was seemingly very > slow on the system. > Two issues: (1) fsync seems to be very slow here (2) fsync is called while > holding a lock. > (2) should be resolved by lazy-loading indexes. > {noformat} > "oak-lucene-22" daemon prio=1 tid=0x6b1 nid=0x runnable >java.lang.Thread.State: RUNNABLE > atjava.io.FileDescriptor.sync(Native Method) > at org.apache.lucene.store.FSDirectory.fsync(FSDirectory.java:505) > at org.apache.lucene.store.FSDirectory.sync(FSDirectory.java:307) > at > org.apache.lucene.store.NRTCachingDirectory.sync(NRTCachingDirectory.java:219) > at > org.apache.lucene.index.IndexWriter.startCommit(IndexWriter.java:4489) > at > org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2953) > - locked <0x20595abf> (a java.lang.Object) > at > org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3049) > - locked <0x20595abf> (a java.lang.Object) > at > org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1041) > at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:932) > - locked <0x20595abf> (a java.lang.Object) > at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:894) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndex.close(NRTIndex.java:206) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory.closeLast(NRTIndexFactory.java:133) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory.createIndex(NRTIndexFactory.java:89) > - locked <0x85f9b65> (a > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory) > at > org.apache.jackrabbit.oak.plugins.index.lucene.LuceneIndexNodeManager.open(LuceneIndexNodeManager.java:73) > at > org.apache.jackrabbit.oak.plugins.index.lucene.IndexTracker$1.leave(IndexTracker.java:154) > at > org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:152) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$WrappingDiff.childNodeChanged(CompositeNodeState.java:309) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$ChildrenDiffFilter.childNodeChanged(CompositeNodeState.java:256) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compareExisting(JsopNodeStateDiffer.java:100) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.access$000(JsopNodeStateDiffer.java:27) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer$1.childNodeChanged(JsopNodeStateDiffer.java:65) > at > org.apache.jackrabbit.oak.plugins.document.DiffCache.parseJsopDiff(DiffCache.java:118) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compare(JsopNodeStateDiffer.java:51) > at > org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.compare(DocumentNodeStore.java:1766) > at > org.apache.jackrabbit.oak.plugins.document.AbstractDocumentNodeState.compareAgainstBaseState(AbstractDocumentNodeState.java:113) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState.compareAgainstBaseState(CompositeNodeState.java:163) > at > org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$WrappingDiff.childNodeChanged(CompositeNodeState.java:309) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$ChildrenDiffFilter.childNodeChanged(CompositeNodeState.java:256) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compareExisting(JsopNodeStateDiffer.java:100) > at > org.apache.jackrabbit.oak.plugin
[jira] [Commented] (OAK-8067) Measure fsync (called when closing the NRT index)
[ https://issues.apache.org/jira/browse/OAK-8067?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16774143#comment-16774143 ] Thomas Mueller commented on OAK-8067: - I removed the "deleteAll" call. Still, I kept close(false), meaning merge won't be done sometimes. I wonder if that's a problem or not? > Measure fsync (called when closing the NRT index) > - > > Key: OAK-8067 > URL: https://issues.apache.org/jira/browse/OAK-8067 > Project: Jackrabbit Oak > Issue Type: Improvement > Components: lucene >Reporter: Thomas Mueller >Assignee: Thomas Mueller >Priority: Major > > We have seen the following stack trace, and saw that fsync was seemingly very > slow on the system. > Two issues: (1) fsync seems to be very slow here (2) fsync is called while > holding a lock. > (2) should be resolved by lazy-loading indexes. > {noformat} > "oak-lucene-22" daemon prio=1 tid=0x6b1 nid=0x runnable >java.lang.Thread.State: RUNNABLE > atjava.io.FileDescriptor.sync(Native Method) > at org.apache.lucene.store.FSDirectory.fsync(FSDirectory.java:505) > at org.apache.lucene.store.FSDirectory.sync(FSDirectory.java:307) > at > org.apache.lucene.store.NRTCachingDirectory.sync(NRTCachingDirectory.java:219) > at > org.apache.lucene.index.IndexWriter.startCommit(IndexWriter.java:4489) > at > org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2953) > - locked <0x20595abf> (a java.lang.Object) > at > org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3049) > - locked <0x20595abf> (a java.lang.Object) > at > org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1041) > at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:932) > - locked <0x20595abf> (a java.lang.Object) > at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:894) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndex.close(NRTIndex.java:206) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory.closeLast(NRTIndexFactory.java:133) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory.createIndex(NRTIndexFactory.java:89) > - locked <0x85f9b65> (a > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory) > at > org.apache.jackrabbit.oak.plugins.index.lucene.LuceneIndexNodeManager.open(LuceneIndexNodeManager.java:73) > at > org.apache.jackrabbit.oak.plugins.index.lucene.IndexTracker$1.leave(IndexTracker.java:154) > at > org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:152) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$WrappingDiff.childNodeChanged(CompositeNodeState.java:309) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$ChildrenDiffFilter.childNodeChanged(CompositeNodeState.java:256) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compareExisting(JsopNodeStateDiffer.java:100) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.access$000(JsopNodeStateDiffer.java:27) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer$1.childNodeChanged(JsopNodeStateDiffer.java:65) > at > org.apache.jackrabbit.oak.plugins.document.DiffCache.parseJsopDiff(DiffCache.java:118) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compare(JsopNodeStateDiffer.java:51) > at > org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.compare(DocumentNodeStore.java:1766) > at > org.apache.jackrabbit.oak.plugins.document.AbstractDocumentNodeState.compareAgainstBaseState(AbstractDocumentNodeState.java:113) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState.compareAgainstBaseState(CompositeNodeState.java:163) > at > org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$WrappingDiff.childNodeChanged(CompositeNodeState.java:309) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$ChildrenDiffFilter.childNodeChanged(CompositeNodeState.java:256) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compareExisting(JsopNodeStateDiffer.java:100) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.access$000(JsopNodeStateDiffer.java:27) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer$1.childNodeChanged(JsopNodeStateDiffer.java:65) > at > org.apache.jackrabbit.oak.plugins.document.DiffCache.parseJsopDiff(DiffCache.java:118) > at > org.apache.jackrabbit.oak.plugins.do
[jira] [Commented] (OAK-8067) Measure fsync (called when closing the NRT index)
[ https://issues.apache.org/jira/browse/OAK-8067?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16774145#comment-16774145 ] Thomas Mueller commented on OAK-8067: - http://svn.apache.org/r1854057 > Measure fsync (called when closing the NRT index) > - > > Key: OAK-8067 > URL: https://issues.apache.org/jira/browse/OAK-8067 > Project: Jackrabbit Oak > Issue Type: Improvement > Components: lucene >Reporter: Thomas Mueller >Assignee: Thomas Mueller >Priority: Major > > We have seen the following stack trace, and saw that fsync was seemingly very > slow on the system. > Two issues: (1) fsync seems to be very slow here (2) fsync is called while > holding a lock. > (2) should be resolved by lazy-loading indexes. > {noformat} > "oak-lucene-22" daemon prio=1 tid=0x6b1 nid=0x runnable >java.lang.Thread.State: RUNNABLE > atjava.io.FileDescriptor.sync(Native Method) > at org.apache.lucene.store.FSDirectory.fsync(FSDirectory.java:505) > at org.apache.lucene.store.FSDirectory.sync(FSDirectory.java:307) > at > org.apache.lucene.store.NRTCachingDirectory.sync(NRTCachingDirectory.java:219) > at > org.apache.lucene.index.IndexWriter.startCommit(IndexWriter.java:4489) > at > org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2953) > - locked <0x20595abf> (a java.lang.Object) > at > org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3049) > - locked <0x20595abf> (a java.lang.Object) > at > org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1041) > at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:932) > - locked <0x20595abf> (a java.lang.Object) > at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:894) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndex.close(NRTIndex.java:206) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory.closeLast(NRTIndexFactory.java:133) > at > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory.createIndex(NRTIndexFactory.java:89) > - locked <0x85f9b65> (a > org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory) > at > org.apache.jackrabbit.oak.plugins.index.lucene.LuceneIndexNodeManager.open(LuceneIndexNodeManager.java:73) > at > org.apache.jackrabbit.oak.plugins.index.lucene.IndexTracker$1.leave(IndexTracker.java:154) > at > org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:152) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$WrappingDiff.childNodeChanged(CompositeNodeState.java:309) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$ChildrenDiffFilter.childNodeChanged(CompositeNodeState.java:256) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compareExisting(JsopNodeStateDiffer.java:100) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.access$000(JsopNodeStateDiffer.java:27) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer$1.childNodeChanged(JsopNodeStateDiffer.java:65) > at > org.apache.jackrabbit.oak.plugins.document.DiffCache.parseJsopDiff(DiffCache.java:118) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compare(JsopNodeStateDiffer.java:51) > at > org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.compare(DocumentNodeStore.java:1766) > at > org.apache.jackrabbit.oak.plugins.document.AbstractDocumentNodeState.compareAgainstBaseState(AbstractDocumentNodeState.java:113) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState.compareAgainstBaseState(CompositeNodeState.java:163) > at > org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$WrappingDiff.childNodeChanged(CompositeNodeState.java:309) > at > org.apache.jackrabbit.oak.composite.CompositeNodeState$ChildrenDiffFilter.childNodeChanged(CompositeNodeState.java:256) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compareExisting(JsopNodeStateDiffer.java:100) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.access$000(JsopNodeStateDiffer.java:27) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer$1.childNodeChanged(JsopNodeStateDiffer.java:65) > at > org.apache.jackrabbit.oak.plugins.document.DiffCache.parseJsopDiff(DiffCache.java:118) > at > org.apache.jackrabbit.oak.plugins.document.JsopNodeStateDiffer.compare(JsopNodeStateDiffer.java:51) > at > org.apache.jackrabbit.oak.plu