Improve warning value extraction performance in Response #50208

darrenfoong · 2019-12-15T13:42:54Z

This PR is similar to #24114 by @jasontedor.

Warnings are returned in REST responses (Response) when a deprecated feature is used. A regular expression in Response (identical to that in DeprecationLogger) is used to capture the warning. As mentioned in #24114, this regular expression suffers from excessive backtracking, and caused a StackOverflowError in my High Level REST Client, which was using the -Xss JVM option that reduced the size of the stack.

Even if a client were to use a normal stack size, the optimization that was used in DeprecationLogger could mean performance improvements when handling REST responses (albeit only when there are warnings). A quick benchmark showed that the substring method (around 10 μs) is 50x faster than the regex method (around 500 μs).

Some notes:

Given the similarity with Improve performance of extracting warning value #24114, I saw a possibility of creating a utility class to handle the matching/extraction in both Response and DeprecationLogger. However, I am not familiar enough with the Elasticsearch code base to determine where is a good place to put this utility class.
The new code in getWarnings() also assumes that all warnings follow the WARNING_HEADER_PATTERN format.

…sponse to improve performance

jasontedor

Thanks for picking this up @darrenfoong!

The new code in getWarnings() also assumes that all warnings follow the WARNING_HEADER_PATTERN format.

This assumption is not valid for the REST client. The problem here is the REST client could be connecting through an HTTP proxy, which might add its own warning headers. There is no guarantee these warnings headers can be parsed with this code. This is why the original implementation checked if the warning header matched the pattern, and extracted the warning, and otherwise copied the entire content of the header value.

All is not lost here, we only need to avoid blowing up if the warning header is not in the format that we expect it in. We can do this without a regular expression, and without over-complicating the code. Can you take a stab at that?

elasticmachine · 2019-12-15T18:34:54Z

Pinging @elastic/es-core-features (:Core/Features/Java Low Level REST Client)

…ueFromWarningHeader()

darrenfoong · 2019-12-16T03:00:24Z

I added matchWarningHeaderPatternByPrefix(String) to match a warning header by a simple prefix. However, the tests were failing here because extractWarningValueFromWarningHeader(String) was not handling dates in warning headers.

Therefore I added a new regex (!) to match the date and remove it. Fortunately this regex can be optimized to fail fast and prevent backtracking. A quick benchmark showed that this is still 10x faster than the original approach using WARNING_HEADER_PATTERN.

jasontedor · 2020-01-11T14:59:18Z

Sorry for the delay here, holidays and all that. I'll review this in the next day.

jasontedor

The production code looks good, I left a few minor comments. It looks like we're lacking test coverage here. Can you add some basic tests to check the extraction logic for:

a valid warning with a date
a valid warning without a date
a warning that is not an Elasticsearch-formatted warning (e.g., added by a proxy)

client/rest/src/main/java/org/elasticsearch/client/Response.java

…RNING_HEADER_DATE_PATTERN

… a sample warning from RFC 7234

darrenfoong · 2020-01-12T10:34:09Z

I've addressed the comments, and also updated RestClientSingleHostTests.testDeprecationWarnings() to cover:

Elasticsearch warnings without dates, and
A sample warning from RFC 7234 (non-Elasticsearch warnings had already been covered, but I thought an actual warning would still be a better test case)

jasontedor · 2020-01-12T20:49:22Z

@elasticmachine update branch

jasontedor · 2020-01-12T20:49:37Z

@elasticmachine test this please

jasontedor · 2020-01-12T20:50:35Z

@elasticmachine test this please

jasontedor

LGTM.

This commit improves the performance of warning value extraction in the low-level REST client, and is similar to the approach taken in #24114. There are some differences since the low-level REST client might be connected to Elasticsearch through a proxy that injects its own warnings.

jasontedor · 2020-01-13T16:19:53Z

Thanks a lot @darrenfoong!

darrenfoong · 2020-01-14T14:37:54Z

Thanks @jasontedor for the guidance! Is there a reason why this will not be included in 6.8.7? I'm using 6.x, although I can still do without this patch by tweaking the -Xss of my JVM.

This commit improves the performance of warning value extraction in the low-level REST client, and is similar to the approach taken in be connected to Elasticsearch through a proxy that injects its own warnings.

jasontedor · 2020-01-15T00:01:35Z

I backported this to 6.8 too.

darrenfoong · 2020-01-15T16:00:53Z

Thanks!

This commit improves the performance of warning value extraction in the low-level REST client, and is similar to the approach taken in elastic#24114. There are some differences since the low-level REST client might be connected to Elasticsearch through a proxy that injects its own warnings.

SledgeHammer01 · 2020-03-31T13:29:18Z

I backported this to 6.8 too.

Hi Jason, Spring Boot 2.2.6 upgraded to 6.8.7 and this fix is causing issues:

2020-03-30 12:30:51.549  WARN 58892 --- [O dispatcher 13] org.elasticsearch.client.RestClient      : request [PUT http://localhost:9200/
kibana_sample_data_flights/_mapping/_doc?master_timeout=30s&include_type_name=true&timeout=30s] returned 1 warnings: [299 Elasticsearch-
7.6.1-aa751e09be0a5072e8570670309b1f12348f023b "[types removal] Using include_type_name in put mapping requests is deprecated. The param
eter will be removed in the next major version."]
Exception in thread "I/O dispatcher 13" java.lang.AssertionError
        at org.elasticsearch.client.Response.assertWarningValue(Response.java:193)
        at org.elasticsearch.client.Response.extractWarningValueFromWarningHeader(Response.java:183)
        at org.elasticsearch.client.Response.getWarnings(Response.java:205)
        at org.elasticsearch.client.RestClient$1.completed(RestClient.java:546)
        at org.elasticsearch.client.RestClient$1.completed(RestClient.java:537)
        at org.apache.http.concurrent.BasicFuture.completed(BasicFuture.java:122)
        at org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl.responseCompleted(DefaultClientExchangeHandlerImpl.java:181)

        at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.processResponse(HttpAsyncRequestExecutor.java:448)
        at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.inputReady(HttpAsyncRequestExecutor.java:338)
        at org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:265)
        at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:81)
        at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:39)
        at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:114)
        at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
        at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
        at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
        at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
        at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
        at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:591)
        at java.base/java.lang.Thread.run(Thread.java:834)
2020-03-30 12:30:52.498 ERROR 58892 --- [pool-3-thread-1] o.a.h.i.n.c.InternalHttpAsyncClient      : I/O reactor terminated abnormally

org.apache.http.nio.reactor.IOReactorException: I/O dispatch worker terminated abnormally
        at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor.execute(AbstractMultiworkerIOReactor.java:359) ~[httpcore-nio-4.4.13.jar:4.4.13]
        at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager.execute(PoolingNHttpClientConnectionManager.java:221) ~[httpasyncclient-4.1.4.jar:4.1.4]
        at org.apache.http.impl.nio.client.CloseableHttpAsyncClientBase$1.run(CloseableHttpAsyncClientBase.java:64) ~[httpasyncclient-4.1.4.jar:4.1.4]
        at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]
Caused by: java.lang.AssertionError: null
        at org.elasticsearch.client.Response.assertWarningValue(Response.java:193) ~[elasticsearch-rest-client-6.8.7.jar:6.8.7]
        at org.elasticsearch.client.Response.extractWarningValueFromWarningHeader(Response.java:183) ~[elasticsearch-rest-client-6.8.7.jar:6.8.7]
        at org.elasticsearch.client.Response.getWarnings(Response.java:205) ~[elasticsearch-rest-client-6.8.7.jar:6.8.7]
        at org.elasticsearch.client.RestClient$1.completed(RestClient.java:546) ~[elasticsearch-rest-client-6.8.7.jar:6.8.7]
        at org.elasticsearch.client.RestClient$1.completed(RestClient.java:537) ~[elasticsearch-rest-client-6.8.7.jar:6.8.7]
        at org.apache.http.concurrent.BasicFuture.completed(BasicFuture.java:122) ~[httpcore4.4.13.jar:4.4.13]
        at org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl.responseCompleted(DefaultClientExchangeHandlerImpl.java:181) ~[httpasyncclient-4.1.4.jar:4.1.4]
        at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.processResponse(HttpAsyncRequestExecutor.java:448) ~[httpcore-nio-4.4.13.jar:4.4.13]
        at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.inputReady(HttpAsyncRequestExecutor.java:338) ~[httpcore-nio-4.4.13.jar:4.4.13]
        at org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:265) ~[httpcore-nio-4.4.13.jar:4.4.13]
        at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:81) ~[httpasyncclient-4.1.4.jar:4.1.4]
        at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:39) ~[httpasyncclient-4.1.4.jar:4.1.4]
        at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:114) ~[httpcore-nio-4.4.13.jar:4.4.13]

        at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162) ~[httpcore-nio-4.4.13.jar:4.4.13]
        at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337) ~[httpcore-nio-4.4.13.jar:4.4.13]

        at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315) ~[httpcore-nio-4.4.13.jar:4.4.13]
        at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276) ~[httpcore-nio-4.4.13.jar:4.4.13]
        at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104) ~[httpcore-nio-4.4.13.jar:4.4.13]
        at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:591) ~[httpcore-nio-4.4.13.jar:4.4.13]
        ... 1 common frames omitted

darrenfoong · 2020-03-31T15:03:07Z

Hi Jason, Spring Boot 2.2.6 upgraded to 6.8.7 and this fix is causing issues:

It seems that you're running against Elasticsearch 7.6.1, which is returning a warning whose hash is longer than the seven characters expected by WARNING_HEADER_PATTERN.

Add extractWarningValueFromWarningHeader from DeprecationLogger to Re…

d4058de

…sponse to improve performance

jasontedor requested changes Dec 15, 2019

View reviewed changes

jasontedor added the :Clients/Java Low Level REST Client Minimal dependencies Java Client for Elasticsearch label Dec 15, 2019

jasontedor added v6.8.7 v7.5.2 v7.6.0 v8.0.0 labels Dec 15, 2019

darrenfoong added 6 commits December 16, 2019 08:01

Add matchWarningHeaderPatternByPrefix

7e94368

Fix Javadoc

d507d2d

Update matchWarningHeaderPatternByPrefix() to strip dates

f7ac690

Fix previous commit; date removal should be done in extractWarningVal…

ae29214

…ueFromWarningHeader()

Fix formatting

c7b15d9

Remove final keyword

564cb8a

darrenfoong requested a review from jasontedor December 16, 2019 03:12

jasontedor reviewed Jan 11, 2020

View reviewed changes

client/rest/src/main/java/org/elasticsearch/client/Response.java Outdated Show resolved Hide resolved

client/rest/src/main/java/org/elasticsearch/client/Response.java Show resolved Hide resolved

darrenfoong added 3 commits January 12, 2020 17:46

Update WARNING_HEADER_DATE_LENGTH constant to reflect structure of WA…

a493561

…RNING_HEADER_DATE_PATTERN

Rewrite comment to use 140 column limit

2b096ea

Update testDeprecationWarnings() to cover warnings without dates, and…

08b53eb

… a sample warning from RFC 7234

darrenfoong requested a review from jasontedor January 12, 2020 10:41

Merge branch 'master' into warning-value-performance

eaf2db5

jasontedor approved these changes Jan 13, 2020

View reviewed changes

jasontedor merged commit a6a3d2b into elastic:master Jan 13, 2020

jasontedor added >bug and removed v6.8.7 labels Jan 13, 2020

jasontedor added the v6.8.7 label Jan 15, 2020

This was referenced Feb 3, 2020

[meta] 7.6 release elastic/elasticsearch-net#4340

Closed

[meta] 7.6 release elastic/elasticsearch-net#4341

Closed

SledgeHammer01 mentioned this pull request Mar 31, 2020

6.8.7 / #50208 causing problems in Spring Boot 2.2.6 #54501

Closed

jakelandis added v8.0.0-alpha1 and removed v8.0.0 labels Jul 26, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Improve warning value extraction performance in Response #50208

Improve warning value extraction performance in Response #50208

darrenfoong commented Dec 15, 2019

jasontedor left a comment •

edited

Loading

elasticmachine commented Dec 15, 2019

darrenfoong commented Dec 16, 2019

jasontedor commented Jan 11, 2020

jasontedor left a comment

darrenfoong commented Jan 12, 2020

jasontedor commented Jan 12, 2020

jasontedor commented Jan 12, 2020

jasontedor commented Jan 12, 2020

jasontedor left a comment

jasontedor commented Jan 13, 2020

darrenfoong commented Jan 14, 2020

jasontedor commented Jan 15, 2020

darrenfoong commented Jan 15, 2020

SledgeHammer01 commented Mar 31, 2020 •

edited

Loading

darrenfoong commented Mar 31, 2020

Improve warning value extraction performance in Response #50208

Improve warning value extraction performance in Response #50208

Conversation

darrenfoong commented Dec 15, 2019

jasontedor left a comment • edited Loading

Choose a reason for hiding this comment

elasticmachine commented Dec 15, 2019

darrenfoong commented Dec 16, 2019

jasontedor commented Jan 11, 2020

jasontedor left a comment

Choose a reason for hiding this comment

darrenfoong commented Jan 12, 2020

jasontedor commented Jan 12, 2020

jasontedor commented Jan 12, 2020

jasontedor commented Jan 12, 2020

jasontedor left a comment

Choose a reason for hiding this comment

jasontedor commented Jan 13, 2020

darrenfoong commented Jan 14, 2020

jasontedor commented Jan 15, 2020

darrenfoong commented Jan 15, 2020

SledgeHammer01 commented Mar 31, 2020 • edited Loading

darrenfoong commented Mar 31, 2020

jasontedor left a comment •

edited

Loading

SledgeHammer01 commented Mar 31, 2020 •

edited

Loading