Skip to content

Instantly share code, notes, and snippets.

@ajhalani
Last active August 29, 2015 13:56
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save ajhalani/8976792 to your computer and use it in GitHub Desktop.
Save ajhalani/8976792 to your computer and use it in GitHub Desktop.
Hot threads for a node doing merge segments very slowly
::: [machine1.node2][ghkgV2QNSPe0_mqBtPkk7A][inet[/10.126.143.197:9311]]{datacenter=nj, master=true}
75.3% (376.5ms out of 500ms) cpu usage by thread 'elasticsearch[machine1.node2][[myindex_20140211][9]: Lucene Merge Thread #155]'
2/10 snapshots sharing following 14 elements
org.apache.lucene.codecs.BlockTreeTermsWriter$TermsWriter.writeBlocks(BlockTreeTermsWriter.java:720)
org.apache.lucene.codecs.BlockTreeTermsWriter$TermsWriter$FindBlocks.freeze(BlockTreeTermsWriter.java:544)
org.apache.lucene.util.fst.Builder.freezeTail(Builder.java:214)
org.apache.lucene.util.fst.Builder.add(Builder.java:394)
org.apache.lucene.codecs.BlockTreeTermsWriter$TermsWriter.finishTerm(BlockTreeTermsWriter.java:1000)
org.apache.lucene.codecs.TermsConsumer.merge(TermsConsumer.java:112)
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
2/10 snapshots sharing following 21 elements
sun.nio.ch.NativeThread.current(Native Method)
sun.nio.ch.NativeThreadSet.add(NativeThreadSet.java:46)
sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:670)
org.apache.lucene.store.NIOFSDirectory$NIOFSIndexInput.readInternal(NIOFSDirectory.java:169)
org.apache.lucene.store.BufferedIndexInput.refill(BufferedIndexInput.java:271)
org.apache.lucene.store.BufferedIndexInput.readBytes(BufferedIndexInput.java:137)
org.apache.lucene.store.BufferedIndexInput.readBytes(BufferedIndexInput.java:113)
org.apache.lucene.codecs.BlockTreeTermsReader$FieldReader$SegmentTermsEnum$Frame.loadBlock(BlockTreeTermsReader.java:2400)
org.apache.lucene.codecs.BlockTreeTermsReader$FieldReader$SegmentTermsEnum$Frame.loadNextFloorBlock(BlockTreeTermsReader.java:2340)
org.apache.lucene.codecs.BlockTreeTermsReader$FieldReader$SegmentTermsEnum.next(BlockTreeTermsReader.java:2115)
org.apache.lucene.index.MultiTermsEnum.pushTop(MultiTermsEnum.java:292)
org.apache.lucene.index.MultiTermsEnum.next(MultiTermsEnum.java:318)
org.apache.lucene.codecs.TermsConsumer.merge(TermsConsumer.java:103)
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
6/10 snapshots sharing following 8 elements
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
63.2% (315.9ms out of 500ms) cpu usage by thread 'elasticsearch[machine1.node2][[myindex_20140211][6]: Lucene Merge Thread #198]'
6/10 snapshots sharing following 17 elements
org.apache.lucene.store.BufferedIndexInput.refill(BufferedIndexInput.java:271)
org.apache.lucene.store.BufferedIndexInput.readBytes(BufferedIndexInput.java:137)
org.apache.lucene.store.BufferedIndexInput.readBytes(BufferedIndexInput.java:113)
org.apache.lucene.codecs.lucene41.ForUtil.readBlock(ForUtil.java:197)
org.apache.lucene.codecs.lucene41.Lucene41PostingsReader$BlockDocsAndPositionsEnum.refillDocs(Lucene41PostingsReader.java:744)
org.apache.lucene.codecs.lucene41.Lucene41PostingsReader$BlockDocsAndPositionsEnum.nextDoc(Lucene41PostingsReader.java:813)
org.apache.lucene.codecs.MappingMultiDocsAndPositionsEnum.nextDoc(MappingMultiDocsAndPositionsEnum.java:104)
org.apache.lucene.codecs.PostingsConsumer.merge(PostingsConsumer.java:109)
org.apache.lucene.codecs.TermsConsumer.merge(TermsConsumer.java:164)
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
2/10 snapshots sharing following 24 elements
java.lang.Thread.sleep(Native Method)
java.lang.Thread.sleep(Thread.java:338)
org.apache.lucene.store.RateLimiter$SimpleRateLimiter.pause(RateLimiter.java:112)
org.apache.lucene.store.RateLimitedFSDirectory$RateLimitedIndexOutput.flushBuffer(RateLimitedFSDirectory.java:100)
org.apache.lucene.store.BufferedChecksumIndexOutput.flushBuffer(BufferedChecksumIndexOutput.java:71)
org.apache.lucene.store.BufferedIndexOutput.flushBuffer(BufferedIndexOutput.java:113)
org.apache.lucene.store.BufferedIndexOutput.flush(BufferedIndexOutput.java:102)
org.apache.lucene.store.BufferedChecksumIndexOutput.flush(BufferedChecksumIndexOutput.java:86)
org.apache.lucene.store.BufferedIndexOutput.writeBytes(BufferedIndexOutput.java:92)
org.elasticsearch.index.store.Store$StoreIndexOutput.writeBytes(Store.java:634)
org.apache.lucene.store.DataOutput.writeBytes(DataOutput.java:52)
org.apache.lucene.store.RAMOutputStream.writeTo(RAMOutputStream.java:65)
org.apache.lucene.codecs.MultiLevelSkipListWriter.writeSkip(MultiLevelSkipListWriter.java:173)
org.apache.lucene.codecs.lucene41.Lucene41PostingsWriter.finishTerm(Lucene41PostingsWriter.java:497)
org.apache.lucene.codecs.BlockTreeTermsWriter$TermsWriter.finishTerm(BlockTreeTermsWriter.java:1002)
org.apache.lucene.codecs.TermsConsumer.merge(TermsConsumer.java:166)
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
2/10 snapshots sharing following 9 elements
org.apache.lucene.codecs.TermsConsumer.merge(TermsConsumer.java:164)
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
32.3% (161.6ms out of 500ms) cpu usage by thread 'elasticsearch[machine1.node2][search][T#2]'
10/10 snapshots sharing following 10 elements
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
org.elasticsearch.common.util.concurrent.jsr166y.LinkedTransferQueue.awaitMatch(LinkedTransferQueue.java:706)
org.elasticsearch.common.util.concurrent.jsr166y.LinkedTransferQueue.xfer(LinkedTransferQueue.java:615)
org.elasticsearch.common.util.concurrent.jsr166y.LinkedTransferQueue.take(LinkedTransferQueue.java:1109)
org.elasticsearch.common.util.concurrent.SizeBlockingQueue.take(SizeBlockingQueue.java:162)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:722)
::: [machine1.node2][ghkgV2QNSPe0_mqBtPkk7A][inet[/10.126.143.197:9311]]{datacenter=nj, master=true}
77.1% (385.6ms out of 500ms) cpu usage by thread 'elasticsearch[machine1.node2][[myindex_20140211][9]: Lucene Merge Thread #155]'
5/10 snapshots sharing following 12 elements
org.apache.lucene.codecs.BlockTreeTermsReader$FieldReader$SegmentTermsEnum.next(BlockTreeTermsReader.java:2157)
org.apache.lucene.index.MultiTermsEnum.pushTop(MultiTermsEnum.java:292)
org.apache.lucene.index.MultiTermsEnum.next(MultiTermsEnum.java:318)
org.apache.lucene.codecs.TermsConsumer.merge(TermsConsumer.java:103)
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
5/10 snapshots sharing following 9 elements
org.apache.lucene.codecs.TermsConsumer.merge(TermsConsumer.java:110)
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
60.5% (302.6ms out of 500ms) cpu usage by thread 'elasticsearch[machine1.node2][[myindex_20140211][6]: Lucene Merge Thread #198]'
10/10 snapshots sharing following 9 elements
org.apache.lucene.codecs.TermsConsumer.merge(TermsConsumer.java:110)
org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:72)
org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:383)
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:106)
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4071)
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3668)
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
23.1% (115.4ms out of 500ms) cpu usage by thread 'elasticsearch[machine1.node2][search][T#29]'
3/10 snapshots sharing following 23 elements
sun.nio.ch.FileDispatcherImpl.pread0(Native Method)
sun.nio.ch.FileDispatcherImpl.pread(FileDispatcherImpl.java:51)
sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:222)
sun.nio.ch.IOUtil.read(IOUtil.java:198)
sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:674)
org.apache.lucene.store.NIOFSDirectory$NIOFSIndexInput.readInternal(NIOFSDirectory.java:169)
org.apache.lucene.store.BufferedIndexInput.refill(BufferedIndexInput.java:271)
org.apache.lucene.store.BufferedIndexInput.readByte(BufferedIndexInput.java:51)
org.apache.lucene.store.DataInput.readVInt(DataInput.java:108)
org.apache.lucene.store.BufferedIndexInput.readVInt(BufferedIndexInput.java:218)
org.apache.lucene.codecs.compressing.CompressingStoredFieldsReader.visitDocument(CompressingStoredFieldsReader.java:231)
org.apache.lucene.index.SegmentReader.document(SegmentReader.java:276)
org.apache.lucene.index.BaseCompositeReader.document(BaseCompositeReader.java:110)
org.apache.lucene.search.IndexSearcher.doc(IndexSearcher.java:196)
org.elasticsearch.search.fetch.FetchPhase.loadStoredFields(FetchPhase.java:214)
org.elasticsearch.search.fetch.FetchPhase.execute(FetchPhase.java:144)
org.elasticsearch.search.SearchService.executeScan(SearchService.java:217)
org.elasticsearch.search.action.SearchServiceTransportAction$SearchScanScrollTransportHandler.messageReceived(SearchServiceTransportAction.java:791)
org.elasticsearch.search.action.SearchServiceTransportAction$SearchScanScrollTransportHandler.messageReceived(SearchServiceTransportAction.java:780)
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:270)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:722)
2/10 snapshots sharing following 23 elements
sun.nio.ch.FileDispatcherImpl.pread0(Native Method)
sun.nio.ch.FileDispatcherImpl.pread(FileDispatcherImpl.java:51)
sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:222)
sun.nio.ch.IOUtil.read(IOUtil.java:198)
sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:674)
org.apache.lucene.store.NIOFSDirectory$NIOFSIndexInput.readInternal(NIOFSDirectory.java:169)
org.apache.lucene.store.BufferedIndexInput.refill(BufferedIndexInput.java:271)
org.apache.lucene.store.BufferedIndexInput.readByte(BufferedIndexInput.java:51)
org.apache.lucene.codecs.compressing.LZ4.decompress(LZ4.java:90)
org.apache.lucene.codecs.compressing.CompressionMode$4.decompress(CompressionMode.java:135)
org.apache.lucene.codecs.compressing.CompressingStoredFieldsReader.visitDocument(CompressingStoredFieldsReader.java:336)
org.apache.lucene.index.SegmentReader.document(SegmentReader.java:276)
org.apache.lucene.index.BaseCompositeReader.document(BaseCompositeReader.java:110)
org.apache.lucene.search.IndexSearcher.doc(IndexSearcher.java:196)
org.elasticsearch.search.fetch.FetchPhase.loadStoredFields(FetchPhase.java:214)
org.elasticsearch.search.fetch.FetchPhase.execute(FetchPhase.java:144)
org.elasticsearch.search.SearchService.executeScan(SearchService.java:217)
org.elasticsearch.search.action.SearchServiceTransportAction$SearchScanScrollTransportHandler.messageReceived(SearchServiceTransportAction.java:791)
org.elasticsearch.search.action.SearchServiceTransportAction$SearchScanScrollTransportHandler.messageReceived(SearchServiceTransportAction.java:780)
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:270)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:722)
2/10 snapshots sharing following 16 elements
org.elasticsearch.common.compress.BufferRecycler.allocDecodeBuffer(BufferRecycler.java:137)
org.elasticsearch.common.compress.lzf.LZFCompressedStreamInput.<init>(LZFCompressedStreamInput.java:46)
org.elasticsearch.common.compress.lzf.LZFCompressor.streamInput(LZFCompressor.java:135)
org.elasticsearch.common.xcontent.XContentHelper.convertToMap(XContentHelper.java:110)
org.elasticsearch.common.xcontent.XContentHelper.convertToMap(XContentHelper.java:75)
org.elasticsearch.search.lookup.SourceLookup.sourceAsMap(SourceLookup.java:77)
org.elasticsearch.search.lookup.SourceLookup.loadSourceIfNeeded(SourceLookup.java:58)
org.elasticsearch.search.lookup.SourceLookup.extractValue(SourceLookup.java:124)
org.elasticsearch.search.fetch.FetchPhase.execute(FetchPhase.java:178)
org.elasticsearch.search.SearchService.executeScan(SearchService.java:217)
org.elasticsearch.search.action.SearchServiceTransportAction$SearchScanScrollTransportHandler.messageReceived(SearchServiceTransportAction.java:791)
org.elasticsearch.search.action.SearchServiceTransportAction$SearchScanScrollTransportHandler.messageReceived(SearchServiceTransportAction.java:780)
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:270)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:722)
3/10 snapshots sharing following 14 elements
org.apache.lucene.codecs.compressing.CompressionMode$4.decompress(CompressionMode.java:135)
org.apache.lucene.codecs.compressing.CompressingStoredFieldsReader.visitDocument(CompressingStoredFieldsReader.java:336)
org.apache.lucene.index.SegmentReader.document(SegmentReader.java:276)
org.apache.lucene.index.BaseCompositeReader.document(BaseCompositeReader.java:110)
org.apache.lucene.search.IndexSearcher.doc(IndexSearcher.java:196)
org.elasticsearch.search.fetch.FetchPhase.loadStoredFields(FetchPhase.java:214)
org.elasticsearch.search.fetch.FetchPhase.execute(FetchPhase.java:144)
org.elasticsearch.search.SearchService.executeScan(SearchService.java:217)
org.elasticsearch.search.action.SearchServiceTransportAction$SearchScanScrollTransportHandler.messageReceived(SearchServiceTransportAction.java:791)
org.elasticsearch.search.action.SearchServiceTransportAction$SearchScanScrollTransportHandler.messageReceived(SearchServiceTransportAction.java:780)
org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.run(MessageChannelHandler.java:270)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:722)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment