Hieu: The stack trace you shared, is from a search request with a mvel script in a function_score query. I don't think that this is causing threads to get stuck and it just pops up here because in general a query with scripts take more cpu time. You can easily verify this if you stop search requests temporarily then the shared stacktrace shouldn't be included in the hot threads output. If a node gets slower over time there may be a different issue. For example the jvm is slowly running out of memory and garbage collections taking are longer.
On 10 September 2014 05:26, Hieu Nguyen <h...@quora.com> wrote: > Thanks for the response, Martijn! We'll consider upgrading, but it'd be > great to root cause the issue. > > On Tuesday, September 9, 2014 12:03:57 AM UTC-7, Martijn v Groningen wrote: >> >> Patrick: I have never seen this, but this means the openjdk on FreeBSD >> doesn't support cpu sampling of threads. Not sure, but maybe you can try >> with an Oracle jdk/jre? Otherwise jstack should be used on order to figure >> out on what threads of ES get stuck on. >> >> Hieu: This doesn't look like the issue that is fixed, since the threads >> are in mvel (scripting) code and not in scan/scroll code. 0.90.12 is an old >> version and I would recommend to upgrade. Also mvel is deprecated and will >> only be available via a plugin: https://github.com/ >> elasticsearch/elasticsearch/pull/6571 and https://github.com/ >> elasticsearch/elasticsearch/pull/6610 >> >> >> On 6 September 2014 16:12, Hieu Nguyen <hi...@quora.com> wrote: >> >>> We have seen a similar issue in our cluster (CPU usage and search time >>> suddenly went up slowly for the master node over a period of one day, until >>> we restarted). Is there a easy way to confirm that it's indeed the same >>> issue mentioned here? >>> >>> Below is the output of our hot threads on this node (version 0.90.12): >>> >>> 85.8% (857.7ms out of 1s) cpu usage by thread >>> 'elasticsearch[cluster1][search][T#3]' >>> 8/10 snapshots sharing following 30 elements >>> java.lang.ThreadLocal$ThreadLocalMap.set(ThreadLocal.java:429) >>> java.lang.ThreadLocal$ThreadLocalMap.access$100( >>> ThreadLocal.java:261) >>> java.lang.ThreadLocal.set(ThreadLocal.java:183) >>> org.elasticsearch.common.mvel2.optimizers.OptimizerFactory. >>> clearThreadAccessorOptimizer(OptimizerFactory.java:114) >>> org.elasticsearch.common.mvel2.MVELRuntime.execute( >>> MVELRuntime.java:169) >>> org.elasticsearch.common.mvel2.compiler.CompiledExpression. >>> getDirectValue(CompiledExpression.java:123) >>> org.elasticsearch.common.mvel2.compiler. >>> CompiledExpression.getValue(CompiledExpression.java:119) >>> org.elasticsearch.script.mvel.MvelScriptEngineService$ >>> MvelSearchScript.run(MvelScriptEngineService.java:191) >>> org.elasticsearch.script.mvel.MvelScriptEngineService$ >>> MvelSearchScript.runAsDouble(MvelScriptEngineService.java:206) >>> org.elasticsearch.common.lucene.search.function. >>> ScriptScoreFunction.score(ScriptScoreFunction.java:54) >>> org.elasticsearch.common.lucene.search.function. >>> FunctionScoreQuery$CustomBoostFactorScorer.score( >>> FunctionScoreQuery.java:175) >>> org.apache.lucene.search.TopScoreDocCollector$ >>> OutOfOrderTopScoreDocCollector.collect(TopScoreDocCollector.java:140) >>> org.apache.lucene.search.TimeLimitingCollector.collect( >>> TimeLimitingCollector.java:153) >>> org.apache.lucene.search.Scorer.score(Scorer.java:65) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:621) >>> org.elasticsearch.search.internal.ContextIndexSearcher. >>> search(ContextIndexSearcher.java:162) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:491) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:448) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:281) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:269) >>> org.elasticsearch.search.query.QueryPhase.execute( >>> QueryPhase.java:117) >>> org.elasticsearch.search.SearchService.executeQueryPhase( >>> SearchService.java:244) >>> org.elasticsearch.search.action.SearchServiceTransportAction. >>> sendExecuteQuery(SearchServiceTransportAction.java:202) >>> org.elasticsearch.action.search.type. >>> TransportSearchQueryThenFetchAction$AsyncAction.sendExecuteFirstPhase( >>> TransportSearchQueryThenFetchAction.java:80) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:216) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:203) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction$2.run(TransportSearchTypeAction.java:186) >>> java.util.concurrent.ThreadPoolExecutor.runWorker( >>> ThreadPoolExecutor.java:1145) >>> java.util.concurrent.ThreadPoolExecutor$Worker.run( >>> ThreadPoolExecutor.java:615) >>> java.lang.Thread.run(Thread.java:744) >>> 2/10 snapshots sharing following 20 elements >>> org.apache.lucene.search.FilteredDocIdSet$1.get( >>> FilteredDocIdSet.java:65) >>> org.apache.lucene.search.FilteredQuery$QueryFirstScorer.nextDoc( >>> FilteredQuery.java:178) >>> org.elasticsearch.common.lucene.search.function. >>> FunctionScoreQuery$CustomBoostFactorScorer.nextDoc(FunctionScoreQuery. >>> java:169) >>> org.apache.lucene.search.Scorer.score(Scorer.java:64) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:621) >>> org.elasticsearch.search.internal.ContextIndexSearcher. >>> search(ContextIndexSearcher.java:162) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:491) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:448) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:281) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:269) >>> org.elasticsearch.search.query.QueryPhase.execute( >>> QueryPhase.java:117) >>> org.elasticsearch.search.SearchService.executeQueryPhase( >>> SearchService.java:244) >>> org.elasticsearch.search.action.SearchServiceTransportAction. >>> sendExecuteQuery(SearchServiceTransportAction.java:202) >>> org.elasticsearch.action.search.type. >>> TransportSearchQueryThenFetchAction$AsyncAction.sendExecuteFirstPhase( >>> TransportSearchQueryThenFetchAction.java:80) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:216) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:203) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction$2.run(TransportSearchTypeAction.java:186) >>> java.util.concurrent.ThreadPoolExecutor.runWorker( >>> ThreadPoolExecutor.java:1145) >>> java.util.concurrent.ThreadPoolExecutor$Worker.run( >>> ThreadPoolExecutor.java:615) >>> java.lang.Thread.run(Thread.java:744) >>> >>> 83.3% (832.6ms out of 1s) cpu usage by thread >>> 'elasticsearch[cluster1][search][T#49]' >>> 9/10 snapshots sharing following 30 elements >>> java.lang.ThreadLocal$ThreadLocalMap.set(ThreadLocal.java:429) >>> java.lang.ThreadLocal$ThreadLocalMap.access$100( >>> ThreadLocal.java:261) >>> java.lang.ThreadLocal.set(ThreadLocal.java:183) >>> org.elasticsearch.common.mvel2.optimizers.OptimizerFactory. >>> clearThreadAccessorOptimizer(OptimizerFactory.java:114) >>> org.elasticsearch.common.mvel2.MVELRuntime.execute( >>> MVELRuntime.java:169) >>> org.elasticsearch.common.mvel2.compiler.CompiledExpression. >>> getDirectValue(CompiledExpression.java:123) >>> org.elasticsearch.common.mvel2.compiler. >>> CompiledExpression.getValue(CompiledExpression.java:119) >>> org.elasticsearch.script.mvel.MvelScriptEngineService$ >>> MvelSearchScript.run(MvelScriptEngineService.java:191) >>> org.elasticsearch.script.mvel.MvelScriptEngineService$ >>> MvelSearchScript.runAsDouble(MvelScriptEngineService.java:206) >>> org.elasticsearch.common.lucene.search.function. >>> ScriptScoreFunction.score(ScriptScoreFunction.java:54) >>> org.elasticsearch.common.lucene.search.function. >>> FunctionScoreQuery$CustomBoostFactorScorer.score( >>> FunctionScoreQuery.java:175) >>> org.apache.lucene.search.TopScoreDocCollector$ >>> OutOfOrderTopScoreDocCollector.collect(TopScoreDocCollector.java:140) >>> org.apache.lucene.search.TimeLimitingCollector.collect( >>> TimeLimitingCollector.java:153) >>> org.apache.lucene.search.Scorer.score(Scorer.java:65) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:621) >>> org.elasticsearch.search.internal.ContextIndexSearcher. >>> search(ContextIndexSearcher.java:162) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:491) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:448) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:281) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:269) >>> org.elasticsearch.search.query.QueryPhase.execute( >>> QueryPhase.java:117) >>> org.elasticsearch.search.SearchService.executeQueryPhase( >>> SearchService.java:244) >>> org.elasticsearch.search.action.SearchServiceTransportAction. >>> sendExecuteQuery(SearchServiceTransportAction.java:202) >>> org.elasticsearch.action.search.type. >>> TransportSearchQueryThenFetchAction$AsyncAction.sendExecuteFirstPhase( >>> TransportSearchQueryThenFetchAction.java:80) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:216) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:203) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction$2.run(TransportSearchTypeAction.java:186) >>> java.util.concurrent.ThreadPoolExecutor.runWorker( >>> ThreadPoolExecutor.java:1145) >>> java.util.concurrent.ThreadPoolExecutor$Worker.run( >>> ThreadPoolExecutor.java:615) >>> java.lang.Thread.run(Thread.java:744) >>> unique snapshot >>> org.apache.lucene.search.DisjunctionMaxScorer.afterNext( >>> DisjunctionMaxScorer.java:65) >>> org.apache.lucene.search.DisjunctionScorer.nextDoc( >>> DisjunctionScorer.java:139) >>> org.apache.lucene.search.DisjunctionScorer.nextDoc( >>> DisjunctionScorer.java:130) >>> org.apache.lucene.search.FilteredQuery$QueryFirstScorer.nextDoc( >>> FilteredQuery.java:177) >>> org.elasticsearch.common.lucene.search.function. >>> FunctionScoreQuery$CustomBoostFactorScorer.nextDoc(FunctionScoreQuery. >>> java:169) >>> org.apache.lucene.search.Scorer.score(Scorer.java:64) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:621) >>> org.elasticsearch.search.internal.ContextIndexSearcher. >>> search(ContextIndexSearcher.java:162) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:491) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:448) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:281) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:269) >>> org.elasticsearch.search.query.QueryPhase.execute( >>> QueryPhase.java:117) >>> org.elasticsearch.search.SearchService.executeQueryPhase( >>> SearchService.java:244) >>> org.elasticsearch.search.action.SearchServiceTransportAction. >>> sendExecuteQuery(SearchServiceTransportAction.java:202) >>> org.elasticsearch.action.search.type. >>> TransportSearchQueryThenFetchAction$AsyncAction.sendExecuteFirstPhase( >>> TransportSearchQueryThenFetchAction.java:80) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:216) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:203) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction$2.run(TransportSearchTypeAction.java:186) >>> java.util.concurrent.ThreadPoolExecutor.runWorker( >>> ThreadPoolExecutor.java:1145) >>> java.util.concurrent.ThreadPoolExecutor$Worker.run( >>> ThreadPoolExecutor.java:615) >>> java.lang.Thread.run(Thread.java:744) >>> >>> 80.2% (802.2ms out of 1s) cpu usage by thread >>> 'elasticsearch[cluster1][search][T#41]' >>> 8/10 snapshots sharing following 30 elements >>> java.lang.ThreadLocal$ThreadLocalMap.set(ThreadLocal.java:429) >>> java.lang.ThreadLocal$ThreadLocalMap.access$100( >>> ThreadLocal.java:261) >>> java.lang.ThreadLocal.set(ThreadLocal.java:183) >>> org.elasticsearch.common.mvel2.optimizers.OptimizerFactory. >>> clearThreadAccessorOptimizer(OptimizerFactory.java:114) >>> org.elasticsearch.common.mvel2.MVELRuntime.execute( >>> MVELRuntime.java:169) >>> org.elasticsearch.common.mvel2.compiler.CompiledExpression. >>> getDirectValue(CompiledExpression.java:123) >>> org.elasticsearch.common.mvel2.compiler. >>> CompiledExpression.getValue(CompiledExpression.java:119) >>> org.elasticsearch.script.mvel.MvelScriptEngineService$ >>> MvelSearchScript.run(MvelScriptEngineService.java:191) >>> org.elasticsearch.script.mvel.MvelScriptEngineService$ >>> MvelSearchScript.runAsDouble(MvelScriptEngineService.java:206) >>> org.elasticsearch.common.lucene.search.function. >>> ScriptScoreFunction.score(ScriptScoreFunction.java:54) >>> org.elasticsearch.common.lucene.search.function. >>> FunctionScoreQuery$CustomBoostFactorScorer.score( >>> FunctionScoreQuery.java:175) >>> org.apache.lucene.search.TopScoreDocCollector$ >>> OutOfOrderTopScoreDocCollector.collect(TopScoreDocCollector.java:140) >>> org.apache.lucene.search.TimeLimitingCollector.collect( >>> TimeLimitingCollector.java:153) >>> org.apache.lucene.search.Scorer.score(Scorer.java:65) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:621) >>> org.elasticsearch.search.internal.ContextIndexSearcher. >>> search(ContextIndexSearcher.java:162) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:491) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:448) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:281) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:269) >>> org.elasticsearch.search.query.QueryPhase.execute( >>> QueryPhase.java:117) >>> org.elasticsearch.search.SearchService.executeQueryPhase( >>> SearchService.java:244) >>> org.elasticsearch.search.action.SearchServiceTransportAction. >>> sendExecuteQuery(SearchServiceTransportAction.java:202) >>> org.elasticsearch.action.search.type. >>> TransportSearchQueryThenFetchAction$AsyncAction.sendExecuteFirstPhase( >>> TransportSearchQueryThenFetchAction.java:80) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:216) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:203) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction$2.run(TransportSearchTypeAction.java:186) >>> java.util.concurrent.ThreadPoolExecutor.runWorker( >>> ThreadPoolExecutor.java:1145) >>> java.util.concurrent.ThreadPoolExecutor$Worker.run( >>> ThreadPoolExecutor.java:615) >>> java.lang.Thread.run(Thread.java:744) >>> 2/10 snapshots sharing following 20 elements >>> org.elasticsearch.common.lucene.search.function. >>> FunctionScoreQuery$CustomBoostFactorScorer.score( >>> FunctionScoreQuery.java:175) >>> org.apache.lucene.search.TopScoreDocCollector$ >>> OutOfOrderTopScoreDocCollector.collect(TopScoreDocCollector.java:140) >>> org.apache.lucene.search.TimeLimitingCollector.collect( >>> TimeLimitingCollector.java:153) >>> org.apache.lucene.search.Scorer.score(Scorer.java:65) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:621) >>> org.elasticsearch.search.internal.ContextIndexSearcher. >>> search(ContextIndexSearcher.java:162) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:491) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:448) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:281) >>> org.apache.lucene.search.IndexSearcher.search( >>> IndexSearcher.java:269) >>> org.elasticsearch.search.query.QueryPhase.execute( >>> QueryPhase.java:117) >>> org.elasticsearch.search.SearchService.executeQueryPhase( >>> SearchService.java:244) >>> org.elasticsearch.search.action.SearchServiceTransportAction. >>> sendExecuteQuery(SearchServiceTransportAction.java:202) >>> org.elasticsearch.action.search.type. >>> TransportSearchQueryThenFetchAction$AsyncAction.sendExecuteFirstPhase( >>> TransportSearchQueryThenFetchAction.java:80) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:216) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:203) >>> org.elasticsearch.action.search.type.TransportSearchTypeAction$ >>> BaseAsyncAction$2.run(TransportSearchTypeAction.java:186) >>> java.util.concurrent.ThreadPoolExecutor.runWorker( >>> ThreadPoolExecutor.java:1145) >>> java.util.concurrent.ThreadPoolExecutor$Worker.run( >>> ThreadPoolExecutor.java:615) >>> java.lang.Thread.run(Thread.java:744) >>> >>> >>> >>> On Thursday, August 28, 2014 11:49:07 PM UTC-7, Martin Forssen wrote: >>>> >>>> FYI, this turned out to be a real bug. A fix has been committed and >>>> will be included in the next release.There >>>> >>>> On Wednesday, August 27, 2014 11:36:03 AM UTC+2, Martin Forssen wrote: >>>>> >>>>> I did report it https://github.com/elasticsearch/elasticsearch/ >>>>> issues/7478 >>>>> >>>>> -- >>> You received this message because you are subscribed to the Google >>> Groups "elasticsearch" group. >>> To unsubscribe from this group and stop receiving emails from it, send >>> an email to elasticsearc...@googlegroups.com. >>> To view this discussion on the web visit https://groups.google.com/d/ >>> msgid/elasticsearch/8c847c08-3850-4821-aedd-04259d0990a2% >>> 40googlegroups.com >>> <https://groups.google.com/d/msgid/elasticsearch/8c847c08-3850-4821-aedd-04259d0990a2%40googlegroups.com?utm_medium=email&utm_source=footer> >>> . >>> >>> For more options, visit https://groups.google.com/d/optout. >>> >> >> >> >> -- >> Met vriendelijke groet, >> >> Martijn van Groningen >> > -- Met vriendelijke groet, Martijn van Groningen -- You received this message because you are subscribed to the Google Groups "elasticsearch" group. To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CA%2BA76TypU1PJavcop_wfzLmimg3%3De%3D%3Dmma-rgRWwYrnXum2c4A%40mail.gmail.com. For more options, visit https://groups.google.com/d/optout.
