You are viewing a plain text version of this content. The canonical link for it is here.
Posted to oak-issues@jackrabbit.apache.org by "Chetan Mehrotra (JIRA)" <ji...@apache.org> on 2016/11/03 14:17:58 UTC
[jira] [Resolved] (OAK-4861) AsyncIndexUpdate consuming constantly
1 CPU core
[ https://issues.apache.org/jira/browse/OAK-4861?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Chetan Mehrotra resolved OAK-4861.
----------------------------------
Resolution: Incomplete
Resolving as incomplete for now due to lack of further logs. On other setup where such issue was seen below changes helped
* Enabling CopyOnWrite
* Adding exclude paths to indexes which index everything to exclude those path which recieve lots of temp writes
> AsyncIndexUpdate consuming constantly 1 CPU core
> ------------------------------------------------
>
> Key: OAK-4861
> URL: https://issues.apache.org/jira/browse/OAK-4861
> Project: Jackrabbit Oak
> Issue Type: Improvement
> Components: query
> Affects Versions: 1.0.31
> Reporter: Jörg Hoh
> Assignee: Chetan Mehrotra
>
> The AsyncIndexUpdate thread takes a long time on some of our environments to update the index for a few nodes:
> {noformat}
> 28.09.2016 18:23:49.405 *DEBUG* [pool-11-thread-1] org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate AsyncIndex (async) update run completed in 3,369 min. Indexed 14 nodes
> {noformat}
> I set the log to DEBUG for investigation and during the time I saw constantly such times; this instance is a test instance and there was no activity from the outside during this time. I also can confirm such times from other environments.
> The immediately visible problem is that this instance (and others as well) constantly consume at least 1 CPU core, no matter what activity happens on the system. This only happens on the master node of our DocumentNodeStore clusters.
> I did a number of threaddumps during investigation and a common stacktrace for the AsyncIndexUpdate was like this:
> {noformat}
> 3XMTHREADINFO "pool-11-thread-1" J9VMThread:0x0000000001E69C00, j9thread_t:0x00007FFFBE101CB0, java/lang/Thread:0x00000001077FE938, state:R, prio=5
> 3XMJAVALTHREAD (java/lang/Thread getId:0x10A, isDaemon:false)
> 3XMTHREADINFO1 (native thread ID:0x3C781, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000001)
> 3XMTHREADINFO2 (native stack address range from:0x00007FFFC696A000, to:0x00007FFFC69AB000, size:0x41000)
> 3XMCPUTIME CPU usage total: 992425.397213554 secs, current category="Application"
> 3XMHEAPALLOC Heap bytes allocated since last GC cycle=735893672 (0x2BDCD8A8)
> 3XMTHREADINFO3 Java callstack:
> 4XESTACKTRACE at com/google/common/collect/Lists.newArrayList(Lists.java:128(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/lucene/OakDirectory$OakIndexFile.<init>(OakDirectory.java:255(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/lucene/OakDirectory$OakIndexFile.<init>(OakDirectory.java:201(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/lucene/OakDirectory$OakIndexInput.<init>(OakDirectory.java:400(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/lucene/OakDirectory$OakIndexInput.clone(OakDirectory.java:408(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/lucene/OakDirectory$OakIndexInput.clone(OakDirectory.java:384(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/store/Directory$SlicedIndexInput.clone(Directory.java:288(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/store/Directory$SlicedIndexInput.clone(Directory.java:269(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/codecs/BlockTreeTermsReader$FieldReader.<init>(BlockTreeTermsReader.java:481(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/codecs/BlockTreeTermsReader.<init>(BlockTreeTermsReader.java:176(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/codecs/lucene41/Lucene41PostingsFormat.fieldsProducer(Lucene41PostingsFormat.java:437(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/index/SegmentCoreReaders.<init>(SegmentCoreReaders.java:116(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/index/SegmentReader.<init>(SegmentReader.java:96(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/index/ReadersAndUpdates.getReader(ReadersAndUpdates.java:141(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/index/BufferedUpdatesStream.applyDeletesAndUpdates(BufferedUpdatesStream.java:279(Compiled Code))
> 5XESTACKTRACE (entered lock: org/apache/lucene/index/BufferedUpdatesStream@0x00000002245B4100, entry count: 1)
> 4XESTACKTRACE at org/apache/lucene/index/IndexWriter.applyAllDeletesAndUpdates(IndexWriter.java:3191(Compiled Code))
> 5XESTACKTRACE (entered lock: org/apache/lucene/index/IndexWriter@0x00000002245B4050, entry count: 3)
> 4XESTACKTRACE at org/apache/lucene/index/IndexWriter.maybeApplyDeletes(IndexWriter.java:3182(Compiled Code))
> 5XESTACKTRACE (entered lock: org/apache/lucene/index/IndexWriter@0x00000002245B4050, entry count: 2)
> 4XESTACKTRACE at org/apache/lucene/index/IndexWriter.doFlush(IndexWriter.java:3155(Compiled Code))
> 5XESTACKTRACE (entered lock: org/apache/lucene/index/IndexWriter@0x00000002245B4050, entry count: 1)
> 4XESTACKTRACE at org/apache/lucene/index/IndexWriter.flush(IndexWriter.java:3123(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/index/IndexWriter.closeInternal(IndexWriter.java:988(Compiled Code))
> 4XESTACKTRACE at org/apache/lucene/index/IndexWriter.close(IndexWriter.java:932(Compiled Code))
> 5XESTACKTRACE (entered lock: java/lang/Object@0x00000002245B9398, entry count: 1)
> 4XESTACKTRACE at org/apache/lucene/index/IndexWriter.close(IndexWriter.java:894(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndexEditorContext.closeWriter(LuceneIndexEditorContext.java:235(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndexEditor.leave(LuceneIndexEditor.java:207(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/IndexUpdate.leave(IndexUpdate.java:250(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/spi/commit/VisibleEditor.leave(VisibleEditor.java:63(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/spi/commit/EditorDiff.process(EditorDiff.java:56(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/AsyncIndexUpdate.updateIndex(AsyncIndexUpdate.java:372(Compiled Code))
> 4XESTACKTRACE at org/apache/jackrabbit/oak/plugins/index/AsyncIndexUpdate.run(AsyncIndexUpdate.java:322(Compiled Code))
> 5XESTACKTRACE (entered lock: org/apache/jackrabbit/oak/plugins/index/AsyncIndexUpdate@0x000000010447CCF0, entry count: 1)
> 4XESTACKTRACE at org/apache/sling/commons/scheduler/impl/QuartzJobExecutor.execute(QuartzJobExecutor.java:115(Compiled Code))
> 4XESTACKTRACE at org/quartz/core/JobRunShell.run(JobRunShell.java:202(Compiled Code))
> 4XESTACKTRACE at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1157(Compiled Code))
> 4XESTACKTRACE at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:627)
> 4XESTACKTRACE at java/lang/Thread.run(Thread.java:809)
> {noformat}
> I don't think, that we had such a behaviour a few months ago.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)