ES error occurred when I ran `geonames` track of Rally


#1

Here is ES error when I ran geonames track of Rally.

org.elasticsearch.transport.RemoteTransportException: [rally-node-0][127.0.0.1:39300][indices:data/read/search[phase/query]]
Caused by: org.elasticsearch.index.query.QueryShardException: failed to create query:
~~very long terms query~~
        at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:329) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:312) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.parseSource(SearchService.java:617) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.createContext(SearchService.java:485) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.createAndPutContext(SearchService.java:461) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:257) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:343) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:340) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.transport.TransportService$7.doRun(TransportService.java:654) [elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:638) [elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.6.4.jar:5.6.4]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_161]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_161]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_161]
Caused by: org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 1024
        at org.apache.lucene.search.BooleanQuery$Builder.add(BooleanQuery.java:125) ~[lucene-core-6.6.1.jar:6.6.1 9aa465a89b64ff2dabe7b4d50c472de32c298683 - varunthacker - 2017-08-29 21:54:39]
        at org.apache.lucene.search.BooleanQuery$Builder.add(BooleanQuery.java:138) ~[lucene-core-6.6.1.jar:6.6.1 9aa465a89b64ff2dabe7b4d50c472de32c298683 - varunthacker - 2017-08-29 21:54:39]
        at org.elasticsearch.index.query.TermsQueryBuilder.handleTermsQuery(TermsQueryBuilder.java:453) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.TermsQueryBuilder.doToQuery(TermsQueryBuilder.java:414) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.AbstractQueryBuilder.toQuery(AbstractQueryBuilder.java:96) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.QueryShardContext.lambda$toQuery$1(QueryShardContext.java:313) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:325) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:312) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.parseSource(SearchService.java:617) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.createContext(SearchService.java:485) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.createAndPutContext(SearchService.java:461) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:257) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:343) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:340) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.transport.TransportService$7.doRun(TransportService.java:654) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:638) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-5.6.4.jar:5.6.4]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_161]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_161]

First, I thought I had an error by using my custom plugin. So I removed plugin option --elasticsearch-plugins=my-plugin. However the same error occurred.
The command that I want to run is below.

$ export ES_JAVA_OPTS="-Djava.security.policy=file://$PATH/plugin-security.policy"; esrally --distribution-version=5.6.4 --user-tag="plugin:geonames" --elasticsearch-plugins=my-plugin

Rally went past the large_xxx operation, but Exception occurred in ES.
I checked cluster setting and got this result.

$ curl -s 'localhost:39200/_cluster/settings?include_defaults=true&pretty' | grep -B3 max_clause_count
      },
      "query" : {
        "bool" : {
          "max_clause_count" : "50000"

But why ES has an error maxClauseCount is set to 1024? I cannot understand that.
please help me


(Daniel Mitterdorfer) #2

Hi,

specifying ES_JAVA_OPTS seems unrelated. Can you please come up with a minimal reproduction that we can try out as well?

  1. Try esrally --distribution-version=5.6.4
  2. Try export ES_JAVA_OPTS="-Djava.security.policy=file://$PATH/plugin-security.policy"; esrally --distribution-version=5.6.4

Do the cases (1) and (2) work?

Afterwards, can you please run a benchmark with:

$ export ES_JAVA_OPTS="-Djava.security.policy=file://$PATH/plugin-security.policy"; esrally --distribution-version=5.6.4 --user-tag="plugin:geonames" --elasticsearch-plugins=my-plugin
--preserve-install=true

And paste the contents of ~/.rally/benchmarks/races/$YOUR_RACETIMESTAMP_HERE/rally-node-0/install/elasticsearch-5.6.4/config/elasticsearch.yml?

$YOUR_RACETIMESTAMP_HERE is the UTC timestamp when you started the benchmark (e.g. 2018-05-11-10-40-13).

Daniel


#3

Thanks for your reply
Here is result

(1) Rally works well
(2) Rally works well but an error occurred in ES

elasticsearch.yml

# ======================== Elasticsearch Configuration =========================
#
# NOTE: Elasticsearch comes with reasonable defaults for most settings.
#       Before you set out to tweak and tune the configuration, make sure you
#       understand what are you trying to accomplish and the consequences.
#
# The primary way of configuring a node is via this file. This template lists
# the most important settings you may want to configure for a production cluster.
#
# Please see the documentation for further information on configuration options:
# <http://www.elastic.co/guide/en/elasticsearch/reference/current/setup-configuration.html>
#
# ---------------------------------- Cluster -----------------------------------
#
# Use a descriptive name for your cluster:
#
cluster.name: rally-benchmark
#
# ------------------------------------ Node ------------------------------------
#
# Use a descriptive name for the node:
#
node.name: rally-node-0
#
# Add custom attributes to the node:
#
#node.attr.rack: r1
#
# ----------------------------------- Paths ------------------------------------
#
# Path to directory where to store the data (separate multiple locations by comma):
#
path.data: ['$MY_PATH/.rally/benchmarks/races/2018-05-14-04-01-47/rally-node-0/install/elasticsearch-5.6.4/data']
#
# Path to log files:
#
path.logs: $MY_PATH/.rally/benchmarks/races/2018-05-14-04-01-47/rally-node-0/logs/server
#
# ----------------------------------- Memory -----------------------------------
#
# Lock the memory on startup:
#
#bootstrap.memory_lock: true
#
# Make sure that the heap size is set to about half the memory available
# on the system and that the owner of the process is allowed to use this
# limit.
#
# Elasticsearch performs poorly when the system is swapping the memory.
#
# ---------------------------------- Network -----------------------------------
#
# Set the bind address to a specific IP (IPv4 or IPv6):
#
network.host: 127.0.0.1
#
# Set a custom port for HTTP:
#
http.port: 39200-39300
transport.tcp.port: 39300-39400
#
# For more information, see the documentation at:
# <http://www.elastic.co/guide/en/elasticsearch/reference/current/modules-network.html>
#
# --------------------------------- Discovery ----------------------------------
#
# Pass an initial list of hosts to perform discovery when new node is started:
# The default list of hosts is ["127.0.0.1", "[::1]"]
#
discovery.zen.ping.unicast.hosts: ["127.0.0.1"]
#
# Prevent the "split brain" by configuring the majority of nodes (total number of nodes / 2 + 1):
#
discovery.zen.minimum_master_nodes: 1
#
# For more information, see the documentation at:
# <http://www.elastic.co/guide/en/elasticsearch/reference/current/modules-discovery.html>
#
# ---------------------------------- Gateway -----------------------------------
#
# Block initial recovery after a full cluster restart until N nodes are started:
#
#gateway.recover_after_nodes: 3
#
# For more information, see the documentation at:
# <http://www.elastic.co/guide/en/elasticsearch/reference/current/modules-gateway.html>
#
# ---------------------------------- Various -----------------------------------
#
# Require explicit names when deleting indices:
#
#action.destructive_requires_name: true
node.max_local_storage_nodes: 1
plugin.mandatory: ["$MY_PLUGIN"]
indices.query.bool.max_clause_count: 50000

Access denied "io.netty.recycler.maxCapacityPerThread"
(Daniel Mitterdorfer) #4

Hi,

can you please describe why you want to set environment variables outside of Rally? We neither test nor support this. If you need to customize your plugin, I recommend you have a look at the Rally docs.

You should follow these steps:

  1. Fork the rally-teams repository, which contains Elasticsearch and plugin configuration.
  2. Add the URL of your fork as new property in ~/rally/rally.ini in the section [teams]. E.g. custom.url = https://github.com/my-fork-of/rally-teams
  3. Add your plugin configuration in your fork. Note that the repo contains one branch for each version of Elasticsearch so be sure to checkout the branch "5" and do your changes there.
  4. Invoke Rally with the additional parameter --team-repository=custom so Rally uses your custom repository.

To your reproduction scenarios:

(1) This shows that Rally itself is properly configured.
(2) This shows that the configuration is somehow not picked up although it shows up properly as indices.query.bool.max_clause_count: 50000 in elasticsearch.yml.

I tried to reproduce the behaviour you're describing by setting ES_JAVA_OPTS as well before executing Rally (but without referencing a plugin):

export ES_JAVA_OPTS="-Dio.netty.recycler.maxCapacityPerThread=0"; esrally --distribution-version=5.6.4 --test-mode

This worked fine for me, so this problem seems unrelated to Rally? Also note that the plugin security policy should be bundled with the plugin.

Daniel


#5

Thanks for your reply.

plugin-security.policy is bundled with my plugin.
but access denied error occurred.

2018-05-15 09:24:54,443 PID:36336 rally.process INFO b'@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@\n'
2018-05-15 09:24:54,443 PID:36336 rally.process INFO b'@     WARNING: plugin requires additional permissions     @\n'
2018-05-15 09:24:54,443 PID:36336 rally.process INFO b'@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@\n'
2018-05-15 09:24:54,444 PID:36336 rally.process INFO b'* java.util.PropertyPermission io.netty.recycler.maxCapacityPerThread write\n'
2018-05-15 09:24:54,444 PID:36336 rally.process INFO b'See http://docs.oracle.com/javase/8/docs/technotes/guides/security/permissions.html\n'
2018-05-15 09:24:54,444 PID:36336 rally.process INFO b'for descriptions of what these permissions allow and the associated risks.\n'
~~~~
~~~~
2018-05-15 09:24:59,599 PID:36336 rally.launcher INFO rally-node-0 (stdout): Caused by: java.security.AccessControlException: access denied ("java.util.PropertyPermission" "io.netty.recycler.maxCapacityPerThread" "write")

So I added this option ES_JAVA_OPTS="-Dio.netty.recycler.maxCapacityPerThread=0" when I started rally. So Access Denied error has disappeared.
However, there was an error maxClauseCount was set to 1024.

My plugin use PreBuiltTransportClient. when it initialize, it should set io.netty.recycler.maxCapacityPerThread property as 0.

I used jvm.option(in teams) which added -Dio.netty.recycler.maxCapacityPerThread = 0
but I got a same result....

It seems that the error unrelated with -Dio.netty.recycler.maxCapacityPerThread = 0 option or ES_JAVA_OPTS
It related with PreBuiltTransportClient. After I removed PreBuiltTransportClient in my plugin code, Rally worked well.
but I should create a new ES client for my plugin logic (it should communicate with another ES).

Thank you for your help.
I was able to erase my wrong assumptions because of your help.
but now I don't know how can I do. T.T

It occurred when I ran ES using Rally.
If I did not use Rally like below, it worked well

$ bin/elasticsearch-plugin install my-plugin
$ bin/elasticsearch

(Daniel Mitterdorfer) #6

Hi,

I still don't quite understand why it behaves in the way you are describing. Can you please provide a small and specific scenario that I can try myself locally?

Daniel


#7

Hi,
This is a simple plugin that creates TransportClient

And Here is a scenario.

  1. add release url in ~/.rally/rally.ini
plugin.test.release.url = https://github.com/llilyy/test-plugin/releases/download/1.0.0/test-1.0.0.zip
  1. start rally
esrally --distribution-version=5.6.4 --elasticsearch-plugins=test --test-mode
  1. maybe you will meet an access denied error.
Caused by: java.security.AccessControlException: access denied ("java.util.PropertyPermission" "io.netty.recycler.maxCapacityPerThread" "write")
  1. for solving access denied error. add command export ES_JAVA_OPTS="-Dio.netty.recycler.maxCapacityPerThread=0"
export ES_JAVA_OPTS="-Dio.netty.recycler.maxCapacityPerThread=0"; esrally --distribution-version=5.6.4 --elasticsearch-plugins=test --test-mode
  1. maybe you will meet warning
[WARNING] No throughput metrics available for [large_terms]. Likely cause: Error rate is 100.0%. Please check the logs.
  1. check ES logs
org.elasticsearch.transport.RemoteTransportException: [rally-node-0][127.0.0.1:39300][indices:data/read/search[phase/query]]
Caused by: org.elasticsearch.index.query.QueryShardException: failed to create query:
~~very long terms query~~
        at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:329) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:312) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.parseSource(SearchService.java:617) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.createContext(SearchService.java:485) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.createAndPutContext(SearchService.java:461) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:257) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:343) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:340) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.transport.TransportService$7.doRun(TransportService.java:654) [elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:638) [elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.6.4.jar:5.6.4]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_161]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_161]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_161]
Caused by: org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 1024
        at org.apache.lucene.search.BooleanQuery$Builder.add(BooleanQuery.java:125) ~[lucene-core-6.6.1.jar:6.6.1 9aa465a89b64ff2dabe7b4d50c472de32c298683 - varunthacker - 2017-08-29 21:54:39]
        at org.apache.lucene.search.BooleanQuery$Builder.add(BooleanQuery.java:138) ~[lucene-core-6.6.1.jar:6.6.1 9aa465a89b64ff2dabe7b4d50c472de32c298683 - varunthacker - 2017-08-29 21:54:39]
        at org.elasticsearch.index.query.TermsQueryBuilder.handleTermsQuery(TermsQueryBuilder.java:453) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.TermsQueryBuilder.doToQuery(TermsQueryBuilder.java:414) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.AbstractQueryBuilder.toQuery(AbstractQueryBuilder.java:96) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.QueryShardContext.lambda$toQuery$1(QueryShardContext.java:313) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:325) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.index.query.QueryShardContext.toQuery(QueryShardContext.java:312) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.parseSource(SearchService.java:617) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.createContext(SearchService.java:485) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.createAndPutContext(SearchService.java:461) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:257) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:343) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.action.search.SearchTransportService$6.messageReceived(SearchTransportService.java:340) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.transport.TransportService$7.doRun(TransportService.java:654) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:638) ~[elasticsearch-5.6.4.jar:5.6.4]
        at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-5.6.4.jar:5.6.4]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_161]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_161]

(Daniel Mitterdorfer) #8

Hi,

thanks for the reproduction scenario. I see now what you mean.

The root cause is that you create a transport client from within your plugin. However, you should instead use the client instance that is passed to you as first parameter in TestPlugin.createComponents(). Can you please change your plugin to use that client instances instead of creating one on your own?

So the code should be as follows:

    public Collection<Object> createComponents(Client client,
                                               ClusterService clusterService,
                                               ThreadPool threadPool,
                                               ResourceWatcherService resourceWatcherService,
                                               ScriptService scriptService,
                                               NamedXContentRegistry xContentRegistry) {
        logger.info("Invoke createComponents");

        ArrayList<Object> components = new ArrayList<>();
        components.add(new TestService(this.settings, client));
        return components;
    }
public class TestService extends AbstractLifecycleComponent {

    private final Logger logger = Loggers.getLogger(TestService.class);
    private final Client client;

    public TestService(Settings settings, Client client) {
        super(settings);
        this.client = client;
    }
    // ...
}

Daniel


#9

Thanks for your reply.

I used localhost for convenience, but in fact, I need to communicate with other ES clusters outside.
so I created a transport client like below.

client = new PreBuiltTransportClient(transportClientSettings)
                    .addTransportAddress(new InetSocketTransportAddress(InetAddress.getByName($OTHER_NODE_IP), 9300));

That is different to local client.
And that does not cause problems when I ran ES without using Rally like below.

$ bin/elasticsearch-plugin install my-plugin
$ bin/elasticsearch

Anyway, I solved a problem by creating REST client instead of transport client.
But I wonder why I cannot create transport client in plugin when I benchmark ES using Rally.
If you do not mind, Could you explain why?

Thanks.


(Daniel Mitterdorfer) #10

Hi,

I dug deeper and the reason you needed to specify the additional system property in Rally is because we missed it from the configuration template so thanks for reporting that! I added it now (see Github). With the newest Rally version 0.11.0 it is not required anymore now to pass the system property.

Note though that the error with due to maxClauseCount being not recognised still persists (and that issue is present regardless of Rally). If you want to talk to remote clusters, the upcoming release Elasticsearch 6.3.0 contains a remote cluster client.

Daniel


#11

Hello.
Thank you for your kindness :slight_smile:
I will follow your advice.

Thank you.


(system) #12

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