Help understanding Hotthreads Snapshot -> IndexReader.hashCode, FilterLeafReader, WeightedSpanTermExtractor

Hi there, I've been working with Elasticsearch for about two weeks now so still trying to figure things out. My use-case is that I have some json files stored as rows in multiple MySQL tables and I'm trying to index them all in the same place to ease searching for specific, related documents. These JSON files can have multiple levels of nested fields and objects, but are not particularly large in size - the whole index is only 78MB with 171 documents.

The whole thing mostly works but I get some timeouts from Kibana when I try to do a simple search for a single date and I'm trying to understand why. From the logs I can see I'm spening 25% of my time doing GC. Can someone explain what the underlying issue might be if I get this snapshot:

::: {oiWBrYk}{oiWBrYkYT8qeElqgGx5a-g}{pUeBGDuDTimrWN91rf6MWQ}{127.0.0.1}{127.0.0.1:9300}{ml.enabled=true}
   Hot threads at 2017-09-04T10:57:59.856Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
   50.7% (253.6ms out of 500ms) cpu usage by thread 'elasticsearch[oiWBrYk][search][T#5]'
     8/10 snapshots sharing following 61 elements
       java.lang.System.identityHashCode(Native Method)
       org.apache.lucene.index.IndexReader.hashCode(IndexReader.java:300)
       java.util.WeakHashMap.hash(WeakHashMap.java:298)
       java.util.WeakHashMap.put(WeakHashMap.java:449)
       java.util.Collections$SetFromMap.add(Collections.java:5461)
       java.util.Collections$SynchronizedCollection.add(Collections.java:2035)
       org.apache.lucene.index.IndexReader.registerParentReader(IndexReader.java:136)
       org.apache.lucene.index.FilterLeafReader.<init>(FilterLeafReader.java:307)
       org.apache.lucene.search.highlight.WeightedSpanTermExtractor$DelegatingLeafReader.<init>(WeightedSpanTermExtractor.java:430)
       org.apache.lucene.search.highlight.WeightedSpanTermExtractor.getLeafContext(WeightedSpanTermExtractor.java:415)
       org.apache.lucene.search.highlight.WeightedSpanTermExtractor.extractWeightedTerms(WeightedSpanTermExtractor.java:363)
       org.apache.lucene.search.highlight.WeightedSpanTermExtractor.extract(WeightedSpanTermExtractor.java:142)
       org.elasticsearch.search.fetch.subphase.highlight.CustomQueryScorer$CustomWeightedSpanTermExtractor.extract(CustomQueryScorer.java:94)
       org.apache.lucene.search.highlight.WeightedSpanTermExtractor.extract(WeightedSpanTermExtractor.java:148)
       org.elasticsearch.search.fetch.subphase.highlight.CustomQueryScorer$CustomWeightedSpanTermExtractor.extract(CustomQueryScorer.java:94)
       org.apache.lucene.search.highlight.WeightedSpanTermExtractor.extract(WeightedSpanTermExtractor.java:156)
       org.elasticsearch.search.fetch.subphase.highlight.CustomQueryScorer$CustomWeightedSpanTermExtractor.extract(CustomQueryScorer.java:94)
       org.apache.lucene.search.highlight.WeightedSpanTermExtractor.extract(WeightedSpanTermExtractor.java:113)
       org.elasticsearch.search.fetch.subphase.highlight.CustomQueryScorer$CustomWeightedSpanTermExtractor.extract(CustomQueryScorer.java:94)
       org.apache.lucene.search.highlight.WeightedSpanTermExtractor.getWeightedSpanTerms(WeightedSpanTermExtractor.java:522)
       org.apache.lucene.search.highlight.QueryScorer.initExtractor(QueryScorer.java:218)
       org.apache.lucene.search.highlight.QueryScorer.init(QueryScorer.java:186)
       org.apache.lucene.search.highlight.Highlighter.getBestTextFragments(Highlighter.java:195)
       org.elasticsearch.search.fetch.subphase.highlight.PlainHighlighter.highlight(PlainHighlighter.java:125)
       org.elasticsearch.search.fetch.subphase.highlight.HighlightPhase.hitExecute(HighlightPhase.java:124)
       org.elasticsearch.search.fetch.FetchPhase.execute(FetchPhase.java:161)
       org.elasticsearch.search.SearchService.executeFetchPhase(SearchService.java:421)
       org.elasticsearch.action.search.SearchTransportService$12.messageReceived(SearchTransportService.java:402)
       org.elasticsearch.action.search.SearchTransportService$12.messageReceived(SearchTransportService.java:399)
       org.elasticsearch.xpack.security.transport.SecurityServerTransportInterceptor$ProfileSecuredRequestHandler$1.doRun(SecurityServerTransportInterceptor.java:258)
       org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
       org.elasticsearch.common.util.concurrent.EsExecutors$1.execute(EsExecutors.java:110)
       org.elasticsearch.xpack.security.transport.SecurityServerTransportInterceptor$ProfileSecuredRequestHandler.lambda$messageReceived$0(SecurityServerTransportInterceptor.java:307)
       org.elasticsearch.xpack.security.transport.SecurityServerTransportInterceptor$ProfileSecuredRequestHandler$$Lambda$1775/502619236.accept(Unknown Source)
       org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:59)
       org.elasticsearch.xpack.security.transport.ServerTransportFilter$NodeProfile.lambda$authorizeAsync$5(ServerTransportFilter.java:191)
       org.elasticsearch.xpack.security.transport.ServerTransportFilter$NodeProfile$$Lambda$1781/212546948.accept(Unknown Source)
       org.elasticsearch.xpack.security.authz.AuthorizationUtils$AsyncAuthorizer.maybeRun(AuthorizationUtils.java:127)
       org.elasticsearch.xpack.security.authz.AuthorizationUtils$AsyncAuthorizer.setRunAsRoles(AuthorizationUtils.java:121)
       org.elasticsearch.xpack.security.authz.AuthorizationUtils$AsyncAuthorizer.authorize(AuthorizationUtils.java:109)
       org.elasticsearch.xpack.security.transport.ServerTransportFilter$NodeProfile.authorizeAsync(ServerTransportFilter.java:193)
       org.elasticsearch.xpack.security.transport.ServerTransportFilter$NodeProfile.lambda$inbound$2(ServerTransportFilter.java:162)
       org.elasticsearch.xpack.security.transport.ServerTransportFilter$NodeProfile$$Lambda$1777/201705869.accept(Unknown Source)
       org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:59)

What is the output of java -version for this server that is running Elasticsearch

Would you please show the code cache size that you are running with?

Thanks for responding, I'm running ES in the official docker image docker.elastic.co/elasticsearch/elasticsearch
Java version:
openjdk version "1.8.0_131"
OpenJDK Runtime Environment (build 1.8.0_131-b12)
OpenJDK 64-Bit Server VM (build 25.131-b12, mixed mode)

Thanks for responding, please could you tell me how to check this, I'm running on a 16GB machine with 12 GB allocated to docker, and 8GB allocated to ES itself using "ES_JAVA_OPTS=-Xms8g -Xmx8g"

Find the PID of your Elasticsearch instance. Using the JDK enter:

$ jinfo -flag ReservedCodeCacheSize <PID>

where <PID> should be replaced by the PID of your Elasticsearch instance.

Just a note here.

I'm running ES in the official docker image docker.elastic.co/elasticsearch/elasticsearch

The "official" image is described here: Install Elasticsearch with Docker | Elasticsearch Guide [8.11] | Elastic

docker pull docker.elastic.co/elasticsearch/elasticsearch:5.5.2

Thanks, yes I am using the official image (docker.elastic.co/elasticsearch/elasticsearch:5.4.3). And thanks for fscrawler, it's amazing.

1 Like

HI, apologies for taking so long to respond. The ReservedCodeCache size is

elasticsearch | uintx ReservedCodeCacheSize = 251658240 {pd product}

Because I'm running in a docker container without jinfo installed I got this information by adding "ES_JAVA_OPTS=-XX:+PrintFlagsFinal -Xms8g -Xmx8g" to my docker options.

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.