Poor indexing performance with 1.4.0

[ZeAleks]

Hello,

I just upgraded my 1.3.2 cluster with 1.4.0 version of Elasticsearch.
As I have some performance counter on some indexing I run, I immediately saw that performances was really bad now.

I don't now where and what to look to find out where is the problem.
I didn't change anything else than the Elasticsearch version.

Does someone have and idea about what can cause this issue ?

Thank you.
Alek

[s1monw]

Alex can you explain what your graph shows?

[ZeAleks]

Yes.
I have some code that index documents (like an ETL).
Every single column is the time taken by one bulk index.

The most revelant and important for me are greens one. About every 10 minutes, I get a CSV file that I parse and index every single lines. I bulk insert 1 000 lines at a time.
So every green column represent the time taken to index 1 000 lines.

[mikemccand]

Are you adding new documents, or updating them (replacing previous versions)? Small or large docs? See this blog post for ways to speed up indexing: http://www.elasticsearch.org/blog/performance-considerations-elasticsearch-indexing/

[ZeAleks]

Hello Michael,
Thank you for your replay.

I do updating existing nested documents to be exact.
The problem is that everything was fine until I upgraded Elasticsearch.

[eliasah]

It might be an error in the visualization framework. You might want to use a load tester like Tsung or Apache JMeter to benchmark your indexing. That would give more insight about where there bottleneck is. Since we can't reproduce your performance issues as for now that would be a good start.

[mikemccand]

Can you capture hot threads while bulk-indexing one of your set of 1000 docs and post here?

[mikemccand]

Also are you using the default index.refresh_interval (1 second)?

[ZeAleks]

Michael,

Everytime I start indexing a file, I set refresh_interval to "60s". "-1" was not working for me.

Here is a capture of hot thread (GET /_nodes/hot_threads) :

::: [S3DEV-BI-ES07][rii902ScRAyuAMiogRhTTQ][S3DEV-BI-ES07][inet[/10.199.67.45:9300]]{master=false} 49.4% (246.7ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES07][bulk][T#2]' 2/10 snapshots sharing following 28 elements java.lang.ClassLoader.defineClass1(Native Method) java.lang.ClassLoader.defineClass(ClassLoader.java:800) java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) groovy.lang.GroovyClassLoader.access$300(GroovyClassLoader.java:56) groovy.lang.GroovyClassLoader$ClassCollector.createClass(GroovyClassLoader.java:478) groovy.lang.GroovyClassLoader$ClassCollector.onClassNode(GroovyClassLoader.java:495) groovy.lang.GroovyClassLoader$ClassCollector.call(GroovyClassLoader.java:499) org.codehaus.groovy.control.CompilationUnit$16.call(CompilationUnit.java:814) org.codehaus.groovy.control.CompilationUnit.applyToPrimaryClassNodes(CompilationUnit.java:1047) org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:583) org.codehaus.groovy.control.CompilationUnit.processPhaseOperations(CompilationUnit.java:561) org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:538) groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:286) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:259) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 5/10 snapshots sharing following 15 elements groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:257) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 3/10 snapshots sharing following 38 elements org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:637) org.codehaus.groovy.control.ResolveVisitor.transformBinaryExpression(ResolveVisitor.java:902) org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:641) org.codehaus.groovy.ast.ClassCodeExpressionTransformer.visitExpressionStatement(ClassCodeExpressionTransformer.java:139) org.codehaus.groovy.ast.stmt.ExpressionStatement.visit(ExpressionStatement.java:40) org.codehaus.groovy.ast.CodeVisitorSupport.visitBlockStatement(CodeVisitorSupport.java:35) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitBlockStatement(ClassCodeVisitorSupport.java:163) org.codehaus.groovy.control.ResolveVisitor.visitBlockStatement(ResolveVisitor.java:1259) org.codehaus.groovy.ast.stmt.BlockStatement.visit(BlockStatement.java:69) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitClassCodeContainer(ClassCodeVisitorSupport.java:101) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitConstructorOrMethod(ClassCodeVisitorSupport.java:112) org.codehaus.groovy.ast.ClassCodeExpressionTransformer.visitConstructorOrMethod(ClassCodeExpressionTransformer.java:50) org.codehaus.groovy.control.ResolveVisitor.visitConstructorOrMethod(ResolveVisitor.java:167) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitMethod(ClassCodeVisitorSupport.java:123) org.codehaus.groovy.ast.ClassNode.visitContents(ClassNode.java:1063) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitClass(ClassCodeVisitorSupport.java:50) org.codehaus.groovy.control.ResolveVisitor.visitClass(ResolveVisitor.java:1202) org.codehaus.groovy.control.ResolveVisitor.startResolving(ResolveVisitor.java:142) org.codehaus.groovy.control.CompilationUnit$11.call(CompilationUnit.java:643) org.codehaus.groovy.control.CompilationUnit.applyToSourceUnits(CompilationUnit.java:923) org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:585) org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:534) groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:286) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:259) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 35.1% (175.3ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES07][bulk][T#1]' 5/10 snapshots sharing following 19 elements groovy.lang.GroovyClassLoader.clearCache(GroovyClassLoader.java:952) org.elasticsearch.script.groovy.GroovyScriptEngineService.scriptRemoved(GroovyScriptEngineService.java:97) org.elasticsearch.script.ScriptService$ScriptCacheRemovalListener.onRemoval(ScriptService.java:509) org.elasticsearch.common.cache.LocalCache.processPendingNotifications(LocalCache.java:1956) org.elasticsearch.common.cache.LocalCache$Segment.runUnlockedCleanup(LocalCache.java:3460) org.elasticsearch.common.cache.LocalCache$Segment.postWriteCleanup(LocalCache.java:3436) org.elasticsearch.common.cache.LocalCache$Segment.put(LocalCache.java:2891) org.elasticsearch.common.cache.LocalCache.put(LocalCache.java:4149) org.elasticsearch.common.cache.LocalCache$LocalManualCache.put(LocalCache.java:4754) org.elasticsearch.script.ScriptService.compile(ScriptService.java:342) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 2/10 snapshots sharing following 56 elements java.security.AccessController.doPrivileged(Native Method) java.net.URLClassLoader.findClass(URLClassLoader.java:354) java.lang.ClassLoader.loadClass(ClassLoader.java:425) sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308) java.lang.ClassLoader.loadClass(ClassLoader.java:412) groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:655) groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:523) org.codehaus.groovy.control.ClassNodeResolver.tryAsLoaderClassOrScript(ClassNodeResolver.java:183) org.codehaus.groovy.control.ClassNodeResolver.findClassNode(ClassNodeResolver.java:168) org.codehaus.groovy.control.ClassNodeResolver.resolveName(ClassNodeResolver.java:124) org.codehaus.groovy.control.ResolveVisitor.resolveToOuter(ResolveVisitor.java:617) org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:269) org.codehaus.groovy.control.ResolveVisitor.resolveFromStaticInnerClasses(ResolveVisitor.java:363) org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:269) org.codehaus.groovy.control.ResolveVisitor.resolveFromModule(ResolveVisitor.java:579) org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:269) org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:237) org.codehaus.groovy.control.ResolveVisitor.transformPropertyExpression(ResolveVisitor.java:774) org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:637) org.codehaus.groovy.control.ResolveVisitor.transformBinaryExpression(ResolveVisitor.java:902) org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:641) org.codehaus.groovy.ast.ClassCodeExpressionTransformer.visitExpressionStatement(ClassCodeExpressionTransformer.java:139) org.codehaus.groovy.ast.stmt.ExpressionStatement.visit(ExpressionStatement.java:40) org.codehaus.groovy.ast.CodeVisitorSupport.visitBlockStatement(CodeVisitorSupport.java:35) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitBlockStatement(ClassCodeVisitorSupport.java:163) org.codehaus.groovy.control.ResolveVisitor.visitBlockStatement(ResolveVisitor.java:1259) org.codehaus.groovy.ast.stmt.BlockStatement.visit(BlockStatement.java:69) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitClassCodeContainer(ClassCodeVisitorSupport.java:101) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitConstructorOrMethod(ClassCodeVisitorSupport.java:112) org.codehaus.groovy.ast.ClassCodeExpressionTransformer.visitConstructorOrMethod(ClassCodeExpressionTransformer.java:50) org.codehaus.groovy.control.ResolveVisitor.visitConstructorOrMethod(ResolveVisitor.java:167) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitMethod(ClassCodeVisitorSupport.java:123) org.codehaus.groovy.ast.ClassNode.visitContents(ClassNode.java:1063) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitClass(ClassCodeVisitorSupport.java:50) org.codehaus.groovy.control.ResolveVisitor.visitClass(ResolveVisitor.java:1202) org.codehaus.groovy.control.ResolveVisitor.startResolving(ResolveVisitor.java:142) org.codehaus.groovy.control.CompilationUnit$11.call(CompilationUnit.java:643) org.codehaus.groovy.control.CompilationUnit.applyToSourceUnits(CompilationUnit.java:923) org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:585) org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:534) groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:286) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:259) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 2/10 snapshots sharing following 41 elements org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:269) org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:237) org.codehaus.groovy.control.ResolveVisitor.transformPropertyExpression(ResolveVisitor.java:774) org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:637) org.codehaus.groovy.control.ResolveVisitor.transformBinaryExpression(ResolveVisitor.java:902) org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:641) org.codehaus.groovy.ast.ClassCodeExpressionTransformer.visitExpressionStatement(ClassCodeExpressionTransformer.java:139) org.codehaus.groovy.ast.stmt.ExpressionStatement.visit(ExpressionStatement.java:40) org.codehaus.groovy.ast.CodeVisitorSupport.visitBlockStatement(CodeVisitorSupport.java:35) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitBlockStatement(ClassCodeVisitorSupport.java:163) org.codehaus.groovy.control.ResolveVisitor.visitBlockStatement(ResolveVisitor.java:1259) org.codehaus.groovy.ast.stmt.BlockStatement.visit(BlockStatement.java:69) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitClassCodeContainer(ClassCodeVisitorSupport.java:101) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitConstructorOrMethod(ClassCodeVisitorSupport.java:112) org.codehaus.groovy.ast.ClassCodeExpressionTransformer.visitConstructorOrMethod(ClassCodeExpressionTransformer.java:50) org.codehaus.groovy.control.ResolveVisitor.visitConstructorOrMethod(ResolveVisitor.java:167) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitMethod(ClassCodeVisitorSupport.java:123) org.codehaus.groovy.ast.ClassNode.visitContents(ClassNode.java:1063) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitClass(ClassCodeVisitorSupport.java:50) org.codehaus.groovy.control.ResolveVisitor.visitClass(ResolveVisitor.java:1202) org.codehaus.groovy.control.ResolveVisitor.startResolving(ResolveVisitor.java:142) org.codehaus.groovy.control.CompilationUnit$11.call(CompilationUnit.java:643) org.codehaus.groovy.control.CompilationUnit.applyToSourceUnits(CompilationUnit.java:923) org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:585) org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:534) groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:286) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:259) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) unique snapshot org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:651) org.codehaus.groovy.control.ResolveVisitor.transformPropertyExpression(ResolveVisitor.java:761) org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:637) org.codehaus.groovy.control.ResolveVisitor.transformBinaryExpression(ResolveVisitor.java:902) org.codehaus.groovy.control.ResolveVisitor.transform(ResolveVisitor.java:641) org.codehaus.groovy.ast.ClassCodeExpressionTransformer.visitExpressionStatement(ClassCodeExpressionTransformer.java:139) org.codehaus.groovy.ast.stmt.ExpressionStatement.visit(ExpressionStatement.java:40) org.codehaus.groovy.ast.CodeVisitorSupport.visitBlockStatement(CodeVisitorSupport.java:35) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitBlockStatement(ClassCodeVisitorSupport.java:163) org.codehaus.groovy.control.ResolveVisitor.visitBlockStatement(ResolveVisitor.java:1259) org.codehaus.groovy.ast.stmt.BlockStatement.visit(BlockStatement.java:69) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitClassCodeContainer(ClassCodeVisitorSupport.java:101) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitConstructorOrMethod(ClassCodeVisitorSupport.java:112) org.codehaus.groovy.ast.ClassCodeExpressionTransformer.visitConstructorOrMethod(ClassCodeExpressionTransformer.java:50) org.codehaus.groovy.control.ResolveVisitor.visitConstructorOrMethod(ResolveVisitor.java:167) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitMethod(ClassCodeVisitorSupport.java:123) org.codehaus.groovy.ast.ClassNode.visitContents(ClassNode.java:1063) org.codehaus.groovy.ast.ClassCodeVisitorSupport.visitClass(ClassCodeVisitorSupport.java:50) org.codehaus.groovy.control.ResolveVisitor.visitClass(ResolveVisitor.java:1202) org.codehaus.groovy.control.ResolveVisitor.startResolving(ResolveVisitor.java:142) org.codehaus.groovy.control.CompilationUnit$11.call(CompilationUnit.java:643) org.codehaus.groovy.control.CompilationUnit.applyToSourceUnits(CompilationUnit.java:923) org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:585) org.codehaus.groovy.control.CompilationUnit.processPhaseOperations(CompilationUnit.java:561) org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:538) groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:286) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:259) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (212.5micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES07][scheduler][T#1]' 10/10 snapshots sharing following 9 elements sun.misc.Unsafe.park(Native Method) java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) ::: [S3DEV-BI-ES03][K0lsh5b4SdOU03R5kQmuEw][S3DEV-BI-ES03][inet[/10.199.31.17:9300]]{master=false} 0.0% (99.4micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES03][scheduler][T#1]' 10/10 snapshots sharing following 9 elements sun.misc.Unsafe.park(Native Method) java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (86.4micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES03][transport_client_worker][T#3]{New I/O worker #3}' 10/10 snapshots sharing following 15 elements sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) org.elasticsearch.common.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:68) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.select(AbstractNioSelector.java:415) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:212) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (27.4micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES03][transport_client_timer][T#1]{Hashed wheel timer #1}' 10/10 snapshots sharing following 5 elements java.lang.Thread.sleep(Native Method) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:445) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:364) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) java.lang.Thread.run(Thread.java:745) ::: [S3DEV-BI-ES02][zHj9goFrT_C1oBNT2PR6xQ][s3dev-bi-es02][inet[/10.199.31.16:9300]]{data=false, master=true} 0.0% (162.6micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES02][scheduler][T#1]' 10/10 snapshots sharing following 9 elements sun.misc.Unsafe.park(Native Method) java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (67.7micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES02][transport_client_worker][T#2]{New I/O worker #2}' 10/10 snapshots sharing following 15 elements sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) org.elasticsearch.common.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:68) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.select(AbstractNioSelector.java:415) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:212) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (29.2micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES02][transport_client_timer][T#1]{Hashed wheel timer #1}' 10/10 snapshots sharing following 5 elements java.lang.Thread.sleep(Native Method) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:445) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:364) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) java.lang.Thread.run(Thread.java:745) ::: [S3DEV-BI-ES04][-4gSCl-kQQKHRniQjNjRGw][S3DEV-BI-ES04][inet[/10.199.31.18:9300]]{master=false} 0.0% (207.9micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES04][scheduler][T#1]' 10/10 snapshots sharing following 9 elements sun.misc.Unsafe.park(Native Method) java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (76.7micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES04][transport_client_worker][T#3]{New I/O worker #3}' 10/10 snapshots sharing following 15 elements sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) org.elasticsearch.common.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:68) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.select(AbstractNioSelector.java:415) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:212) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (28.7micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES04][transport_client_timer][T#1]{Hashed wheel timer #1}' 10/10 snapshots sharing following 5 elements java.lang.Thread.sleep(Native Method) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:445) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:364) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) java.lang.Thread.run(Thread.java:745) ::: [S3DEV-BI-ES06][N2xcaOFLQ2C6F2UcYu7sSA][s3dev-bi-es06][inet[/10.199.31.20:9300]]{master=false} 54.5% (272.6ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES06][bulk][T#2]' 4/10 snapshots sharing following 16 elements groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:286) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:259) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 2/10 snapshots sharing following 19 elements groovy.lang.GroovyClassLoader.clearCache(GroovyClassLoader.java:952) org.elasticsearch.script.groovy.GroovyScriptEngineService.scriptRemoved(GroovyScriptEngineService.java:97) org.elasticsearch.script.ScriptService$ScriptCacheRemovalListener.onRemoval(ScriptService.java:509) org.elasticsearch.common.cache.LocalCache.processPendingNotifications(LocalCache.java:1956) org.elasticsearch.common.cache.LocalCache$Segment.runUnlockedCleanup(LocalCache.java:3460) org.elasticsearch.common.cache.LocalCache$Segment.postWriteCleanup(LocalCache.java:3436) org.elasticsearch.common.cache.LocalCache$Segment.put(LocalCache.java:2891) org.elasticsearch.common.cache.LocalCache.put(LocalCache.java:4149) org.elasticsearch.common.cache.LocalCache$LocalManualCache.put(LocalCache.java:4754) org.elasticsearch.script.ScriptService.compile(ScriptService.java:342) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 2/10 snapshots sharing following 14 elements groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 2/10 snapshots sharing following 7 elements org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 50.1% (250.6ms out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES06][bulk][T#1]' 8/10 snapshots sharing following 14 elements groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:245) groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:203) org.elasticsearch.script.groovy.GroovyScriptEngineService.compile(GroovyScriptEngineService.java:119) org.elasticsearch.script.ScriptService.getCompiledScript(ScriptService.java:353) org.elasticsearch.script.ScriptService.compile(ScriptService.java:339) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 2/10 snapshots sharing following 19 elements groovy.lang.GroovyClassLoader.clearCache(GroovyClassLoader.java:952) org.elasticsearch.script.groovy.GroovyScriptEngineService.scriptRemoved(GroovyScriptEngineService.java:97) org.elasticsearch.script.ScriptService$ScriptCacheRemovalListener.onRemoval(ScriptService.java:509) org.elasticsearch.common.cache.LocalCache.processPendingNotifications(LocalCache.java:1956) org.elasticsearch.common.cache.LocalCache$Segment.runUnlockedCleanup(LocalCache.java:3460) org.elasticsearch.common.cache.LocalCache$Segment.postWriteCleanup(LocalCache.java:3436) org.elasticsearch.common.cache.LocalCache$Segment.put(LocalCache.java:2891) org.elasticsearch.common.cache.LocalCache.put(LocalCache.java:4149) org.elasticsearch.common.cache.LocalCache$LocalManualCache.put(LocalCache.java:4754) org.elasticsearch.script.ScriptService.compile(ScriptService.java:342) org.elasticsearch.script.ScriptService.executable(ScriptService.java:463) org.elasticsearch.action.update.UpdateHelper.prepare(UpdateHelper.java:183) org.elasticsearch.action.bulk.TransportShardBulkAction.shardUpdateOperation(TransportShardBulkAction.java:535) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnPrimary(TransportShardBulkAction.java:240) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction.performOnPrimary(TransportShardReplicationOperationAction.java:511) org.elasticsearch.action.support.replication.TransportShardReplicationOperationAction$AsyncShardOperationAction$1.run(TransportShardReplicationOperationAction.java:419) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (58.9micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES06][transport_client_timer][T#1]{Hashed wheel timer #1}' 10/10 snapshots sharing following 5 elements java.lang.Thread.sleep(Native Method) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:445) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:364) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) java.lang.Thread.run(Thread.java:745) ::: [S3DEV-BI-ES05][RCNDd2psQ9mJdqOGjsap5g][S3DEV-BI-ES05][inet[/10.199.31.19:9300]]{master=false} 0.0% (189.5micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES05][scheduler][T#1]' 10/10 snapshots sharing following 9 elements sun.misc.Unsafe.park(Native Method) java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (73.3micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES05][transport_client_worker][T#3]{New I/O worker #3}' 10/10 snapshots sharing following 15 elements sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) org.elasticsearch.common.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:68) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.select(AbstractNioSelector.java:415) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:212) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (27.8micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES05][transport_client_timer][T#1]{Hashed wheel timer #1}' 10/10 snapshots sharing following 5 elements java.lang.Thread.sleep(Native Method) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:445) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:364) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) java.lang.Thread.run(Thread.java:745) ::: [S3DEV-BI-ES01][ALCO_0FLRsaunFGeC7CkQw][s3dev-bi-es01][inet[/10.199.31.15:9300]]{data=false, master=true} 0.0% (102.4micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES01][[transport_server_worker.default]][T#3]{New I/O worker #8}' 10/10 snapshots sharing following 15 elements sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) org.elasticsearch.common.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:68) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.select(AbstractNioSelector.java:415) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:212) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (33.2micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES01][[transport_server_worker.default]][T#1]{New I/O worker #6}' 10/10 snapshots sharing following 15 elements sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) org.elasticsearch.common.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:68) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.select(AbstractNioSelector.java:415) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:212) org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) java.lang.Thread.run(Thread.java:745) 0.0% (30.5micros out of 500ms) cpu usage by thread 'elasticsearch[S3DEV-BI-ES01][transport_client_timer][T#1]{Hashed wheel timer #1}' 10/10 snapshots sharing following 5 elements java.lang.Thread.sleep(Native Method) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:445) org.elasticsearch.common.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:364) org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) java.lang.Thread.run(Thread.java:745)

[rmuir]

Hi, can you tell us your exact jvm version?

[dakrone]

@ZeAleks can you also share the script and/or a full request you are using to update the documents?

[ZeAleks]

@rmuir : Here is the Java version
java version "1.7.0_65"
OpenJDK Runtime Environment (rhel-2.5.1.2.el6_5-x86_64 u65-b17)
OpenJDK 64-Bit Server VM (build 24.65-b04, mixed mode)

@dakrone : The script is in C#. Do you really want to see it ? It is just looping to everyline of a CSV file. Lines contains 3 columns with int values. It creates a concatenated string of bulk request that will be send to ES. And Every 1 000 lines, it sends the request, empty the string and continue.
Here is an example of what is sent to Elasticsearch in bulk (1 line) :

{"update":{"_id":4242}}
{"script":"ctx._source.StockEvolution+=part;ctx._source.LastStockMovement='20141120-213620';ctx._source.CurrentInitial=42;ctx._source.CurrentSold=42;ctx._source.CurrentReal=42;","params":{"part":[{Date:"20141120-213620",Initial:42,Sold:42,Real:42}]}}

[mikemccand]

@ZeAleks your update scripts change every time? So they must be recompiled for each update? It's better to use the same script and just change the params... I think (not certain) ES will compile them once and reuse that for future updates that have the same script.

With #6571 we switched from mvel to groovy in 1.4.0 so it looks likely that compiling scripts is slower for groovy than it was for mvel, maybe?

[nik9000]

I know that the first point is correct. I'm reasonably sure your second
(compiling is slower) is also correct.

Its OK to have a couple of different scripts but not one per operation.
On Nov 20, 2014 5:02 PM, "Michael McCandless" notifications@github.com
wrote:

@ZeAleks https://github.com/ZeAleks your update scripts change every
time? So they must be recompiled for each update? It's better to use the
same script and just change the params... I think (not certain) ES will
compile them once and reuse that for future updates that have the same
script.

With #6571 #6571 we
switched from mvel to groovy in 1.4.0 so it looks likely that compiling
scripts is slower for groovy than it was for mvel, maybe?

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

[ZeAleks]

OK.
I will try immediately to use parameters in my script.

But, if that is true, so that it mean that mvel has better performance than groovy ?

[dakrone]

@ZeAleks MVEL compiles faster than Groovy (which is why you are seeing compilation show up in the hot threads of your system), however Groovy executes much faster than MVEL. Moving all the changing parts of the script to parameters will ensure that ES only compiles the script once per node, and not every time a request is sent

[s1monw]

@ZeAleks can you try to optimize your script to use parameters? I will close the issue for now - if it's a different cause we can reopen...

[ZeAleks]

Hey guys,

You were right. The problem was cause by my request.
I change it to :
{"update":{"_id":1}}
{"script":"ctx._source.StockEvolution+=part;ctx._source.LastStockMovement=part[0].Date;ctx._source.CurrentInitial=part[0].Initial;ctx._source.CurrentSold=part[0].Sold;ctx._source.CurrentReal=part[0].Real;","params":{"part":[{Date:"2009-11-15T16:22:12",Initial:53,Sold:54,Real:52}]}}

And now it is much better :

But, it is not as fast as it was with 1.3.2 and mvel.
I will try to investigate why.

Anyway, think you all for your support !

[osykora]

I experienced the same issue when I switched to ES 1.4, thus to Groovy, since MVEL is no longer supported. The bulk update script executed slowly, so I tried to parameterized the script and it helped, but it's not as fast as it was using MVEL for the very same script.

Here's my pseudo code for a script that is updating a list in a list:
​{update: {"_id" : "myObjectID" }}
{"script": "for(item in ctx._source.myListOfValues){ if(item.get('field1') == param1 && item.get('field2') == param2 && item.get('field3') == param3) {item.innerListOfValues+=list; break; }} ,"params":{"param1":"someValue", "param2":"someValue2", "param3":"someValue3", "list": ['a', 'b', 'c']}}

[ZeAleks]

Hi osykora,

What I did after my last post was :

• Upgrade to Java 1.8
• Restart every node of my cluster

After that, my queries are as fast as before.