Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Poor indexing performance with elasticsearch 1.5.0 #10409

Closed
ZeAleks opened this issue Apr 3, 2015 · 7 comments
Closed

Poor indexing performance with elasticsearch 1.5.0 #10409

ZeAleks opened this issue Apr 3, 2015 · 7 comments
Assignees
@mikemccand
Labels
feedback_needed

Comments

@ZeAleks
Copy link

ZeAleks commented Apr 3, 2015

Hi again,

I migrated my cluster to elasticsearch 1.5.0 yesterday and I do have performance indexing problem again.
I just lost my logs so I cannot show you any graph to demonstrate it but indexing is about 2x slower.
As I already have this problem (#8553) I run a GET /_nodes/hot_threads.

Notice that the request is always the same.

Here is the result :

::: [S3DEV-BI-ES05][3YlS8B4dRxaFaqSSzyOxew][S3DEV-BI-ES05][inet[/10.199.31.19:9300]]{master=false}
Hot threads at 2015-04-03T09:20:20.490Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

45.8% (229ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES05][bulk][T#2]'
5/10 snapshots sharing following 17 elements
org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:663)
org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:359)
org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:318)
org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:284)
org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:424)
org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1353)
org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:438)
org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
2/10 snapshots sharing following 16 elements
org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:359)
org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:318)
org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:284)
org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:424)
org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1353)
org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:438)
org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
2/10 snapshots sharing following 11 elements
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:552)
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:493)
org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:465)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:423)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
unique snapshot
org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$Composite.parseInto(DateTimeFormatterBuilder.java:2462)
org.elasticsearch.common.joda.time.format.InternalParserDateTimeParser.parseInto(InternalParserDateTimeParser.java:52)
org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$MatchingParser.parseInto(DateTimeFormatterBuilder.java:2556)
org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$Composite.parseInto(DateTimeFormatterBuilder.java:2462)
org.elasticsearch.common.joda.time.format.DateTimeParserBucket.doParseMillis(DateTimeParserBucket.java:179)
org.elasticsearch.common.joda.time.format.DateTimeFormatter.parseMillis(DateTimeFormatter.java:780)
org.elasticsearch.index.mapper.core.DateFieldMapper.parseStringValue(DateFieldMapper.java:613)
org.elasticsearch.index.mapper.core.DateFieldMapper.innerParseCreateField(DateFieldMapper.java:547)
org.elasticsearch.index.mapper.core.NumberFieldMapper.parseCreateField(NumberFieldMapper.java:236)
org.elasticsearch.index.mapper.core.AbstractFieldMapper.parse(AbstractFieldMapper.java:400)
org.elasticsearch.index.mapper.object.ObjectMapper.serializeValue(ObjectMapper.java:706)
org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:497)
org.elasticsearch.index.mapper.object.ObjectMapper.serializeObject(ObjectMapper.java:554)
org.elasticsearch.index.mapper.object.ObjectMapper.serializeNonDynamicArray(ObjectMapper.java:685)
org.elasticsearch.index.mapper.object.ObjectMapper.serializeArray(ObjectMapper.java:604)
org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:489)
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:544)
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:493)
org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:465)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:423)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)

45.7% (228.7ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES05][bulk][T#1]'
2/10 snapshots sharing following 29 elements
org.elasticsearch.common.joda.time.format.InternalParserDateTimeParser.parseInto(InternalParserDateTimeParser.java:52)
org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$MatchingParser.parseInto(DateTimeFormatterBuilder.java:2556)
org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$Composite.parseInto(DateTimeFormatterBuilder.java:2462)
org.elasticsearch.common.joda.time.format.InternalParserDateTimeParser.parseInto(InternalParserDateTimeParser.java:52)
org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$MatchingParser.parseInto(DateTimeFormatterBuilder.java:2556)
org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$Composite.parseInto(DateTimeFormatterBuilder.java:2462)
org.elasticsearch.common.joda.time.format.DateTimeParserBucket.doParseMillis(DateTimeParserBucket.java:179)
org.elasticsearch.common.joda.time.format.DateTimeFormatter.parseMillis(DateTimeFormatter.java:780)
org.elasticsearch.index.mapper.core.DateFieldMapper.parseStringValue(DateFieldMapper.java:613)
org.elasticsearch.index.mapper.core.DateFieldMapper.innerParseCreateField(DateFieldMapper.java:547)
org.elasticsearch.index.mapper.core.NumberFieldMapper.parseCreateField(NumberFieldMapper.java:236)
org.elasticsearch.index.mapper.core.AbstractFieldMapper.parse(AbstractFieldMapper.java:400)
org.elasticsearch.index.mapper.object.ObjectMapper.serializeValue(ObjectMapper.java:706)
org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:497)
org.elasticsearch.index.mapper.object.ObjectMapper.serializeObject(ObjectMapper.java:554)
org.elasticsearch.index.mapper.object.ObjectMapper.serializeNonDynamicArray(ObjectMapper.java:685)
org.elasticsearch.index.mapper.object.ObjectMapper.serializeArray(ObjectMapper.java:604)
org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:489)
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:544)
org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:493)
org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:465)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:423)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
5/10 snapshots sharing following 18 elements
org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:151)
org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:663)
org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:359)
org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:318)
org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:284)
org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:424)
org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1353)
org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:438)
org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
2/10 snapshots sharing following 7 elements
org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
unique snapshot
org.elasticsearch.common.jackson.core.json.UTF8JsonGenerator.writeString(UTF8JsonGenerator.java:436)
org.elasticsearch.common.xcontent.json.JsonXContentGenerator.writeString(JsonXContentGenerator.java:99)
org.elasticsearch.common.xcontent.XContentBuilder.writeValue(XContentBuilder.java:1176)
org.elasticsearch.common.xcontent.XContentBuilder.writeMap(XContentBuilder.java:1163)
org.elasticsearch.common.xcontent.XContentBuilder.writeValue(XContentBuilder.java:1197)
org.elasticsearch.common.xcontent.XContentBuilder.writeValue(XContentBuilder.java:1201)
org.elasticsearch.common.xcontent.XContentBuilder.writeMap(XContentBuilder.java:1163)
org.elasticsearch.common.xcontent.XContentBuilder.map(XContentBuilder.java:1072)
org.elasticsearch.action.index.IndexRequest.source(IndexRequest.java:379)
org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:228)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:523)
org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)

::: [S3DEV-BI-ES06][rF5XW0dVRz689Fbl0Cuh-w][s3dev-bi-es06][inet[/10.199.31.20:9300]]{master=false}
Hot threads at 2015-04-03T09:20:20.295Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: [S3DEV-BI-ES07][8v1UTkWwTsOPFS-aBjMb0w][S3DEV-BI-ES07][inet[/10.199.31.21:9300]]{master=false}
Hot threads at 2015-04-03T09:20:20.283Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: [S3DEV-BI-ES01][lbFh9XQeTyGU-WEBeyMQHA][s3dev-bi-es01][inet[/10.199.31.15:9300]]{data=false, master=true}
Hot threads at 2015-04-03T09:20:20.149Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: [S3DEV-BI-ES04][bjy958SyTjG3-oSqryU9Pw][S3DEV-BI-ES04][inet[/10.199.31.18:9300]]{master=false}
Hot threads at 2015-04-03T09:20:20.349Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

7.6% (38.1ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES04][[operations][2]: Lucene Merge Thread #563]'
 10/10 snapshots sharing following 15 elements
   java.lang.Thread.sleep(Native Method)
   java.lang.Thread.sleep(Thread.java:340)
   org.apache.lucene.store.RateLimiter$SimpleRateLimiter.pause(RateLimiter.java:151)
   org.apache.lucene.store.RateLimitedFSDirectory$RateLimiterWrapper.pause(RateLimitedFSDirectory.java:96)
   org.apache.lucene.store.RateLimitedIndexOutput.checkRate(RateLimitedIndexOutput.java:76)
   org.apache.lucene.store.RateLimitedIndexOutput.writeBytes(RateLimitedIndexOutput.java:70)
   org.apache.lucene.store.CompoundFileWriter$DirectCFSIndexOutput.writeBytes(CompoundFileWriter.java:356)
   org.apache.lucene.store.DataOutput.copyBytes(DataOutput.java:281)
   org.apache.lucene.store.Directory.copy(Directory.java:194)
   org.apache.lucene.index.IndexWriter.createCompoundFile(IndexWriter.java:4785)
   org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4266)
   org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3811)
   org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:409)
   org.apache.lucene.index.TrackingConcurrentMergeScheduler.doMerge(TrackingConcurrentMergeScheduler.java:107)
   org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:486)

7.5% (37.6ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES04][bulk][T#1]'
 3/10 snapshots sharing following 15 elements
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeObject(ObjectMapper.java:554)
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeNonDynamicArray(ObjectMapper.java:685)
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeArray(ObjectMapper.java:604)
   org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:489)
   org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:544)
   org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:493)
   org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:465)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:423)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 5/10 snapshots sharing following 16 elements
   org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:359)
   org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:318)
   org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:284)
   org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:424)
   org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1353)
   org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:438)
   org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
   org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 2/10 snapshots sharing following 14 elements
   org.apache.lucene.index.SegmentReader.document(SegmentReader.java:335)
   org.elasticsearch.search.lookup.SourceLookup.loadSourceIfNeeded(SourceLookup.java:70)
   org.elasticsearch.search.lookup.SourceLookup.extractRawValues(SourceLookup.java:145)
   org.elasticsearch.index.get.ShardGetService.innerGetLoadFromStoredFields(ShardGetService.java:378)
   org.elasticsearch.index.get.ShardGetService.innerGet(ShardGetService.java:210)
   org.elasticsearch.index.get.ShardGetService.get(ShardGetService.java:104)
   org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:77)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:523)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)

7.1% (35.2ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES04][bulk][T#2]'
 3/10 snapshots sharing following 17 elements
   org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:663)
   org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:359)
   org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:318)
   org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:284)
   org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:424)
   org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1353)
   org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:438)
   org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
   org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 2/10 snapshots sharing following 33 elements
   org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$Composite.parseInto(DateTimeFormatterBuilder.java:2462)
   org.elasticsearch.common.joda.time.format.InternalParserDateTimeParser.parseInto(InternalParserDateTimeParser.java:52)
   org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$MatchingParser.parseInto(DateTimeFormatterBuilder.java:2556)
   org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$Composite.parseInto(DateTimeFormatterBuilder.java:2462)
   org.elasticsearch.common.joda.time.format.InternalParserDateTimeParser.parseInto(InternalParserDateTimeParser.java:52)
   org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$MatchingParser.parseInto(DateTimeFormatterBuilder.java:2556)
   org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$Composite.parseInto(DateTimeFormatterBuilder.java:2462)
   org.elasticsearch.common.joda.time.format.InternalParserDateTimeParser.parseInto(InternalParserDateTimeParser.java:52)
   org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$MatchingParser.parseInto(DateTimeFormatterBuilder.java:2556)
   org.elasticsearch.common.joda.time.format.DateTimeFormatterBuilder$Composite.parseInto(DateTimeFormatterBuilder.java:2462)
   org.elasticsearch.common.joda.time.format.DateTimeParserBucket.doParseMillis(DateTimeParserBucket.java:179)
   org.elasticsearch.common.joda.time.format.DateTimeFormatter.parseMillis(DateTimeFormatter.java:780)
   org.elasticsearch.index.mapper.core.DateFieldMapper.parseStringValue(DateFieldMapper.java:613)
   org.elasticsearch.index.mapper.core.DateFieldMapper.innerParseCreateField(DateFieldMapper.java:547)
   org.elasticsearch.index.mapper.core.NumberFieldMapper.parseCreateField(NumberFieldMapper.java:236)
   org.elasticsearch.index.mapper.core.AbstractFieldMapper.parse(AbstractFieldMapper.java:400)
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeValue(ObjectMapper.java:706)
   org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:497)
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeObject(ObjectMapper.java:554)
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeNonDynamicArray(ObjectMapper.java:685)
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeArray(ObjectMapper.java:604)
   org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:489)
   org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:544)
   org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:493)
   org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:465)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:423)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 2/10 snapshots sharing following 17 elements
   org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:668)
   org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:359)
   org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:318)
   org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:284)
   org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:424)
   org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1353)
   org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:438)
   org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
   org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 2/10 snapshots sharing following 7 elements
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:523)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 unique snapshot
   org.apache.lucene.index.TermVectorsConsumerPerField.start(TermVectorsConsumerPerField.java:131)
   org.apache.lucene.index.TermsHashPerField.start(TermsHashPerField.java:297)
   org.apache.lucene.index.FreqProxTermsWriterPerField.start(FreqProxTermsWriterPerField.java:72)
   org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:616)
   org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:359)
   org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:318)
   org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:284)
   org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:424)
   org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1353)
   org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:438)
   org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
   org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)

::: [S3DEV-BI-ES03][a2rQ95QFTYWF-_f0a9ABVg][S3DEV-BI-ES03][inet[/10.199.31.17:9300]]{master=true}
Hot threads at 2015-04-03T09:20:20.355Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

3.6% (18ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES03][bulk][T#2]'
 5/10 snapshots sharing following 15 elements
   org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:318)
   org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:284)
   org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:424)
   org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1353)
   org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:438)
   org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
   org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 2/10 snapshots sharing following 13 elements
   org.elasticsearch.index.mapper.core.AbstractFieldMapper.parse(AbstractFieldMapper.java:400)
   org.elasticsearch.index.mapper.internal.FieldNamesFieldMapper.postParse(FieldNamesFieldMapper.java:183)
   org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:552)
   org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:493)
   org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:465)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:423)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 2/10 snapshots sharing following 15 elements
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeObject(ObjectMapper.java:554)
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeNonDynamicArray(ObjectMapper.java:685)
   org.elasticsearch.index.mapper.object.ObjectMapper.serializeArray(ObjectMapper.java:604)
   org.elasticsearch.index.mapper.object.ObjectMapper.parse(ObjectMapper.java:489)
   org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:544)
   org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:493)
   org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:465)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:423)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)
 unique snapshot
   org.apache.lucene.codecs.blocktree.SegmentTermsEnumFrame.scanToTermLeaf(SegmentTermsEnumFrame.java:566)
   org.apache.lucene.codecs.blocktree.SegmentTermsEnumFrame.scanToTerm(SegmentTermsEnumFrame.java:469)
   org.apache.lucene.codecs.blocktree.SegmentTermsEnum.seekExact(SegmentTermsEnum.java:508)
   org.elasticsearch.common.lucene.uid.PerThreadIDAndVersionLookup.lookup(PerThreadIDAndVersionLookup.java:104)
   org.elasticsearch.common.lucene.uid.Versions.loadDocIdAndVersion(Versions.java:150)
   org.elasticsearch.common.lucene.uid.Versions.loadVersion(Versions.java:161)
   org.elasticsearch.index.engine.InternalEngine.loadCurrentVersionFromIndex(InternalEngine.java:1002)
   org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:404)
   org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:362)
   org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:483)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:427)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:529)
   org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:239)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:515)
   org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:422)
   java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   java.lang.Thread.run(Thread.java:745)

::: [Hardcase/t1][u2qP36hdQfawXLGhhYx3Jw][s3dev-bi-es02][inet[/10.199.31.16:9301]]{data=false, client=true}
Hot threads at 2015-04-03T09:20:20.146Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

I'm not good enough to read those logs so if someone see something I should do ...

Thank you.
@mikemccand
Copy link
Contributor

Do you see any "now throttling indexing" messages in your node console logs?

Maybe try increasing the store throttling (defaults to 20 MB/sec): http://www.elastic.co/guide/en/elasticsearch/reference/1.4/index-modules-store.html

@ZeAleks
Copy link
Author

ZeAleks commented Apr 3, 2015

No.
There is only info about "updating refresh_interval".
No errors, no warnings.

@jhansen-tt
Copy link

Why is more feedback needed? I am seeing ~5x performance decrease in ES 1.5.1, with geoshape documents.

@mikemccand
Copy link
Contributor

Why is more feedback needed?

I was wondering whether increasing the default 20 MB/sec throttle helps.

@jhansen-tt which version of ES did you upgrade from?

I am seeing ~5x performance decrease in ES 1.5.1, with geoshape documents.

Hmm, @nknize did anything change in how we index geoshape docs?

@nknize
Copy link
Contributor

nknize commented Apr 18, 2015

@mikemccand No, geo_shape indexing has not changed in 1.5.1. I'm also curious which version of ES was used previously. As of 1.4.3 the ShapeBuilder enforces OGC ordering, but that will only affect the unwinding for shapes crossing the dateline. @jhansen-tt can you provide your geo_shape mapping?

@jhansen-tt
Copy link

The mapping is simply

“myIndex”: {
“mappings”: {
… other non-geo_shape properties
“data”: {
“properties”: {
“geometry”: {
“type”: “geo_shape”
}
}
}
}
}

On Apr 18, 2015, at 12:02 PM, Nick Knize notifications@github.com wrote:

@mikemccand https://github.com/mikemccand No, geo_shape indexing has not changed in 1.5.1. I'm also curious which version of ES was used previously. As of 1.4.3 the ShapeBuilder enforces OGC ordering, but that will only affect the unwinding for shapes crossing the dateline. @jhansen-tt https://github.com/jhansen-tt can you provide your geo_shape mapping?

—
Reply to this email directly or view it on GitHub #10409 (comment).

@clintongormley
Copy link

So much has changed since 1.5, I'm going to close this issue now.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mikemccand mikemccand

Labels
feedback_needed
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@clintongormley @mikemccand @nknize @ZeAleks @jhansen-tt