Add timeout to ESQL #99526

luigidellaquila · 2023-09-13T12:30:06Z

Adding a timeout to ESQL requests.

By default a query will have no timeout, but it can be overridden adding a timeout parameter to the payload

{
   "timeout": "500ms",
   "query": "from ..."
}

or configuring ES with esql.query.default_timeout: <value>. A value of -1 means no timeout.

The implementation also defines a maximum timeout for queries, disabled by default, that can be configured setting esql.query.max_timeout.
If the value passed in the payload is > max timeout or < 0, then the max timeout will be used.

Fixes #99141

luigidellaquila · 2023-09-13T12:33:18Z

.../plugin/esql/src/main/java/org/elasticsearch/xpack/esql/plugin/TransportEsqlQueryAction.java


 public class TransportEsqlQueryAction extends HandledTransportAction<EsqlQueryRequest, EsqlQueryResponse> {

+    public static TimeValue DEFAULT_TIMEOUT = new TimeValue(4, TimeUnit.MINUTES);
+    public static TimeValue MAX_TIMEOUT = new TimeValue(4, TimeUnit.MINUTES);


The default and max values are supposed to be lower than other timeouts that can happen in the infrastructure, eg. the a http timeouts on cloud proxies.

We shouldn't have MAX_TIMEOUT since ES can be deployed to an environment without the proxy timeout.

Maybe we can move it to a Setting and disable it by default, so that we can enable it when we know we have a proxy timeout.

elasticsearchmachine · 2023-09-13T12:41:32Z

Pinging @elastic/es-ql (Team:QL)

elasticsearchmachine · 2023-09-13T12:41:32Z

Hi @luigidellaquila, I've created a changelog YAML for you.

elasticsearchmachine · 2023-09-13T12:41:32Z

Pinging @elastic/elasticsearch-esql (:Query Languages/ES|QL)

luigidellaquila · 2023-09-13T14:01:27Z

x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/session/EsqlConfiguration.java

        this.pragmas = new QueryPragmas(in);
        this.resultTruncationMaxSize = in.readVInt();
+        this.timeout = in.readOptionalTimeValue();


Does it need a TransportVersion bump since we are in tech preview and serverless is not out yet?

We don't need to bump the version.

Serverless is "out" in the sense that it's running in a production environment and serialization errors during upgrades may trip assertions and block a future release. Please don't skip this.

We are disabling ES|QL in Serverless now to simplify the developement process.

dnhatn

Thanks @luigidellaquila. I've left some comments.

dnhatn · 2023-09-13T16:21:49Z

...ingle-node/src/javaRestTest/java/org/elasticsearch/xpack/esql/qa/single_node/RestEsqlIT.java

+        Response response = client().performRequest(bulk);
+        Assert.assertEquals("{\"errors\":false}", EntityUtils.toString(response.getEntity(), StandardCharsets.UTF_8));
+
+        // let's make it a bit expensive, so that the timeout will most likely trigger


We should create a test plugin to avoid the flakiness here.

I was considering to add a sleep(x) function only in test, to simulate slow queries. Not sure it's what you mean, if you think there is a better way please let me know

dnhatn · 2023-09-13T16:24:18Z

.../plugin/esql/src/main/java/org/elasticsearch/xpack/esql/plugin/TransportEsqlQueryAction.java


 public class TransportEsqlQueryAction extends HandledTransportAction<EsqlQueryRequest, EsqlQueryResponse> {

+    public static TimeValue DEFAULT_TIMEOUT = new TimeValue(4, TimeUnit.MINUTES);
+    public static TimeValue MAX_TIMEOUT = new TimeValue(4, TimeUnit.MINUTES);


We shouldn't have MAX_TIMEOUT since ES can be deployed to an environment without the proxy timeout.

dnhatn · 2023-09-13T16:25:33Z

x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/session/EsqlConfiguration.java

        this.pragmas = new QueryPragmas(in);
        this.resultTruncationMaxSize = in.readVInt();
+        this.timeout = in.readOptionalTimeValue();


We don't need to bump the version.

dnhatn · 2023-09-13T16:39:50Z

.../plugin/esql/src/main/java/org/elasticsearch/xpack/esql/plugin/TransportEsqlQueryAction.java

+    private TimeValue timeout(EsqlQueryRequest request) {
+        TimeValue rTimeout = request.timeout();
+        if (rTimeout == null) {
+            return DEFAULT_TIMEOUT;


I am not sure if we can have the default timeout at the request level here. Once we have the default, it will be very hard to remove as it's considered a breaking change. I think we need to discuss with the team. Let's remove it from this PR, then re-introduce it in a follow-up after the discussion.

I think a default timeout could be a useful feature, but I'll move it to a Setting and I'll set it to -1 (ie. no timeout) by default.
Let's discuss it with the team though, maybe there are better options.

dnhatn · 2023-09-13T16:41:09Z

x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/plugin/ComputeService.java

+        if (configuration.timeout() != null) {
+            return ListenerTimeouts.wrapWithTimeout(pool, configuration.timeout(), esqlExecutor, l, (x) -> {
+                String timeoutMessage = "ESQL query timed out after {}";
+                l.onFailure(new ElasticsearchTimeoutException(timeoutMessage, configuration.timeout()));


We also need to cancel the ESQL request when it's timed out.

…/timeout

luigidellaquila · 2023-09-14T11:16:29Z

@elasticmachine update branch

luigidellaquila · 2023-09-18T14:05:40Z

Turns out that the implementation I did with ListenerTimeouts is incorrect (the tests fail).
@dnhatn let's discuss it off-line, I'm afraid I need some help to better understand where to plug the timeout. I have the feeling (and a TODO in the code someway confirms it) that there are some missing pieces to be able to implement proper cancelation.

dnhatn · 2023-09-18T18:44:51Z

@luigidellaquila The issue is that we need to call onFailure() on the original listener, not the wrapped listener, as the isDone flag is already set to true. Also, we need to wrap the timeout in TransportEsqlQueryAction to ensure that the request can time out even during the resolution. Below is the snippet that we can use in TransportEsqlQueryAction#execute.

@Override
protected void doExecute(Task task, EsqlQueryRequest request, ActionListener<EsqlQueryResponse> listener) {
    // workaround for https://github.com/elastic/elasticsearch/issues/97916 - TODO remove this when we can
    final ActionListener<EsqlQueryResponse> wrappedListener;
    final TimeValue timeout = timeout(request);
    if (timeout != null) {
        final ThreadPool threadPool = transportService.getThreadPool();
        final var executor = threadPool.executor(EsqlPlugin.ESQL_THREAD_POOL_NAME);
        wrappedListener = ListenerTimeouts.wrapWithTimeout(threadPool, timeout, executor, listener, l -> {
            logger.debug("cancelling ESQL task {} on timeout", task);
            final TaskManager taskManager = transportService.getTaskManager();
            taskManager.cancelTaskAndDescendants((CancellableTask) task, "timeout", false, ActionListener.noop());
            listener.onFailure(new ElasticsearchTimeoutException("ESQL query timed out after {}", timeout));
        });
    } else {
        wrappedListener = listener;
    }
    requestExecutor.execute(ActionRunnable.wrap(wrappedListener, l -> doExecuteForked(task, request, l)));
}

dnhatn · 2023-09-18T18:55:15Z

I've pushed 7b71306

DaveCTurner · 2023-09-18T18:57:52Z

.../plugin/esql/src/main/java/org/elasticsearch/xpack/esql/plugin/TransportEsqlQueryAction.java

+            wrappedListener = ListenerTimeouts.wrapWithTimeout(threadPool, timeout, executor, listener, l -> {
+                logger.debug("cancelling ESQL task {} on timeout", task);
+                final TaskManager taskManager = transportService.getTaskManager();
+                taskManager.cancelTaskAndDescendants((CancellableTask) task, "timeout", false, ActionListener.noop());


Even on a timeout we should wait for the child tasks to complete before responding.

I agree; we should wait for all outstanding tasks before responding. I deliberately chose not to wait because of the specific use case we are trying to address. Here, we want users to see the timeout error from Elasticsearch rather than the Cloud proxy. If we wait for outstanding tasks, it's possible that it might exceed the proxy's timeout before we can respond. However, thinking about this more, I believe we should wait and reduce the default timeout instead. Having a parent task completed before its child tasks isn't good.

FWIW I still think we should not try and undercut the proxy timeout by default. Our response is just an exception saying ESQL query timed out after {}, this is not practically any more useful than the proxy timeout message. Put differently, I expect most users who see this response will just increase the timeout in the request until they start to get the proxy timeout message instead. And then there's a good chance they'll open a support case complaining that they can't control the proxy timeout.

+1 to what you said, @DaveCTurner. I would like to hear from @nik9000 and @costin. If we all agree, then we should not introduce the timeout parameter until we really need it.

I can see some value in a timeout parameter. Although generally it's be better to time out on the client side since server-side timeouts will always be a little unreliable and/or late, I think there are some clients that make it harder than they should to do this so a server-side parameter is a nice feature. And server-side timeouts do save the cost of tearing down the connection and opening a new one at least. I just don't think we should have a server-side timeout by default.

DaveCTurner · 2023-09-18T18:59:57Z

.../plugin/esql/src/main/java/org/elasticsearch/xpack/esql/plugin/TransportEsqlQueryAction.java

+                logger.debug("cancelling ESQL task {} on timeout", task);
+                final TaskManager taskManager = transportService.getTaskManager();
+                taskManager.cancelTaskAndDescendants((CancellableTask) task, "timeout", false, ActionListener.noop());
+                listener.onFailure(new ElasticsearchTimeoutException("ESQL query timed out after {}", timeout));


We should complete the supplied listener l rather than the outer listener, otherwise listener may be completed twice (and also to avoid unnecessarily capturing listener in this lambda)

Oh wait sorry, this API is very confusing. What you've written is right.

Why do we even pass in a listener to the onTimeout callback? This listener is a no-op in all cases isn't it?

Yes, I think the API is confusing. I will look into simplifying it.

luigidellaquila · 2023-09-19T08:21:08Z

Thanks for fixing it @dnhatn!

I still see some random failures in the timeout tests:

java.lang.AssertionError: Leftover exchanges ExchangeService{sinks=[AMxhb_ukRK2ZVb_mqZOq_w:38], sources=[]} on node node_s3	
at __randomizedtesting.SeedInfo.seed([20BE10A7D69C7EA3:74AC932D7B1A6D7A]:0)	
at org.junit.Assert.fail(Assert.java:88)	
at org.junit.Assert.assertTrue(Assert.java:41)	
at org.elasticsearch.xpack.esql.action.AbstractEsqlIntegTestCase.lambda$ensureExchangesAreReleased$0(AbstractEsqlIntegTestCase.java:38)

maybe there is something missing in the cancelation?

jpountz

It looks like the approach of this PR is to fail requests when hitting the timeout, I'm curious if we should consider returning a partial response instead.

jpountz · 2023-09-19T10:32:56Z

x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/action/EsqlQueryRequest.java

@@ -166,6 +179,7 @@ private static ObjectParser<EsqlQueryRequest, Void> objectParser(Supplier<EsqlQu
        );
        parser.declareField(EsqlQueryRequest::params, EsqlQueryRequest::parseParams, PARAMS_FIELD, VALUE_ARRAY);
        parser.declareString((request, localeTag) -> request.locale(Locale.forLanguageTag(localeTag)), LOCALE_FIELD);
+        parser.declareInt((request, value) -> request.timeout(new TimeValue(value, TimeUnit.MILLISECONDS)), TIMEOUT_FIELD);


Should we take the timeout as a time value directly like the _search API rather than an int?

luigidellaquila · 2023-09-19T12:59:05Z

I'm curious if we should consider returning a partial response instead.

@jpountz we considered that, but at this stage it's complicated. In the future we will have pagination and partial results, but it will require some additional work

luigidellaquila · 2023-09-19T13:09:08Z

@elasticmachine update branch

elasticmachine · 2023-09-19T13:09:10Z

expected head sha didn’t match current head ref.

luigidellaquila · 2023-09-19T13:16:55Z

expected head sha didn’t match current head ref.

GitHub is having a bad day today, it doesn't see latest commits. Trying to switch branches to see if it recovers

luigidellaquila · 2023-09-19T13:24:53Z

@elasticmachine update branch

luigidellaquila · 2023-09-19T13:28:09Z

@elasticmachine update branch

elasticsearchmachine · 2023-09-20T11:17:42Z

Hi @luigidellaquila, I've updated the changelog YAML for you.

…/timeout

costin · 2023-10-10T17:28:01Z

Folks, thanks for the feedback.
Luigi has been looking into this issue for a while and discovered multiple timeout mechanisms in place:

at the REST layer in ES
in the HTTP(s) library used by the client (Kibana)
at the socket level used by the client infra (e.g. nodeJS)
on any proxies, transparent or not, between the client and ES

As such, introducing yet another timeout on the ESQL endpoint doesn't add any value rather more confusion.
Hence why, it was agreed to close this PR without merging - potential improvements around the cancellation infrastructure will be handled in separate PRs.

Add timeout to ESQL

a3ccc7f

elasticsearchmachine added the v8.11.0 label Sep 13, 2023

luigidellaquila commented Sep 13, 2023

View reviewed changes

luigidellaquila added >enhancement :Analytics/ES|QL AKA ESQL labels Sep 13, 2023

luigidellaquila marked this pull request as ready for review September 13, 2023 12:41

luigidellaquila requested a review from dnhatn September 13, 2023 12:41

elasticsearchmachine added the Team:QL (Deprecated) Meta label for query languages team label Sep 13, 2023

Update docs/changelog/99526.yaml

ac3e392

luigidellaquila commented Sep 13, 2023

View reviewed changes

dnhatn reviewed Sep 13, 2023

View reviewed changes

luigidellaquila added 3 commits September 14, 2023 10:37

Move timeouts to Settings and cancel tasks on timeout

c75823e

Fix settings

2f1856d

Merge remote-tracking branch 'luigidellaquila/esql/timeout' into esql…

f379b90

…/timeout

elasticmachine and others added 3 commits September 14, 2023 21:16

Merge branch 'main' into esql/timeout

6abf543

Merge branch 'main' into esql/timeout

a36ae8a

Add timeout tests

2728c85

Move timeout to TransportEsqlQueryAction

7b71306

dnhatn self-requested a review September 18, 2023 18:55

DaveCTurner reviewed Sep 18, 2023

View reviewed changes

dnhatn added 3 commits September 18, 2023 12:45

Wait for outstanding tasks on timeout

30af9dd

Larger timeout for case without timeout

e40a2bb

Merge remote-tracking branch 'elastic/main' into esql/timeout

193b7ce

Remove max timeout

94e1f90

jpountz reviewed Sep 19, 2023

View reviewed changes

Use time units for timeout configuration

6cf73f2

luigidellaquila changed the base branch from main to feature/esql September 19, 2023 13:22

luigidellaquila requested a review from a team as a code owner September 19, 2023 13:22

luigidellaquila changed the base branch from feature/esql to main September 19, 2023 13:23

luigidellaquila changed the base branch from main to feature/esql September 19, 2023 13:23

luigidellaquila removed the request for review from a team September 19, 2023 13:23

Merge branch 'feature/esql' into esql/timeout

46bba39

luigidellaquila changed the base branch from feature/esql to main September 19, 2023 13:25

Merge branch 'main' into esql/timeout

215565c

costin mentioned this pull request Sep 19, 2023

ESQL: Major Issues for 8.11 #99460

Closed

32 tasks

luigidellaquila added 3 commits September 20, 2023 13:17

Update docs/changelog/99526.yaml

a938286

Merge branch 'main' into esql/timeout

78e2e2c

Merge remote-tracking branch 'luigidellaquila/esql/timeout' into esql…

3992a65

…/timeout

mattc58 added v8.12.0 and removed v8.11.0 labels Oct 4, 2023

costin closed this Oct 10, 2023

costin mentioned this pull request Oct 11, 2023

ESQL: default request timeout #99141

Closed

Add timeout to ESQL #99526

Add timeout to ESQL #99526

Conversation

luigidellaquila commented Sep 13, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

elasticsearchmachine commented Sep 13, 2023

elasticsearchmachine commented Sep 13, 2023

elasticsearchmachine commented Sep 13, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dnhatn left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

luigidellaquila commented Sep 14, 2023

luigidellaquila commented Sep 18, 2023

dnhatn commented Sep 18, 2023 • edited Loading

dnhatn commented Sep 18, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

DaveCTurner Sep 18, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

DaveCTurner Sep 18, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

luigidellaquila commented Sep 19, 2023

jpountz left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

luigidellaquila commented Sep 19, 2023

luigidellaquila commented Sep 19, 2023

elasticmachine commented Sep 19, 2023

luigidellaquila commented Sep 19, 2023

luigidellaquila commented Sep 19, 2023

luigidellaquila commented Sep 19, 2023

elasticsearchmachine commented Sep 20, 2023

costin commented Oct 10, 2023

luigidellaquila commented Sep 13, 2023 •

edited

Loading

dnhatn commented Sep 18, 2023 •

edited

Loading

DaveCTurner Sep 18, 2023 •

edited

Loading

DaveCTurner Sep 18, 2023 •

edited

Loading