HttpClient fails intermittently with "Invalid response state TRANSIENT"

[mperktold]

Jetty version
9.4.32.v20200930

Java version
11.0.8+10

OS type/version

• Windows Server 2012 R2 Standard
• Windows Server 2016 Data Center
• Windows Server 2016 Standard

Description
Since upgrading to Jetty 9.4.31, Requests sent from a Jetty HttpClient in our production system fail intermittently with an error saying "Invalid response state TRANSIENT".
The code that throws this exception resides in HttpReceiver and was introduced here:
e095519#diff-c4aa5ed6568d33c882382bc50f770a82R841

The server to which the failing request should go is a Jetty server of the same version in the same local network.
We are now on 9.4.32, but the problem persists.

It's not clear to us whether the problem is due to a misuse of the HttpClient on our side, or whether it is a bug.
It's also hard to track down, since it fails intermittently and only in production.

Do you have any idea what could be the reason?

[joakime]

Can you share a stacktrace or any debug logging when this occurs?

[mperktold]

Sure, I will gather a stacktrace.

Regarding the logs, we tried activating all Jetty loggers, but that was way to much to the point that the application didn't start anymore.
Can you point out the relevant packages or classes for which you would like to see the logs?

[sbordet]

Please enable DEBUG logs for org.eclipse.jetty.client.HttpReceiver.

[josepowera]

We got something similar. The error does not occur every time (we download always fixed file from fixed server) - FLAPPING.

Using: <jetty.version>9.4.31.v20200723</jetty.version>

java.io.IOException: java.lang.IllegalStateException: Invalid response state TRANSIENT at org.eclipse.jetty.client.util.InputStreamResponseListener$Input.toIOException(InputStreamResponseListener.java:345) at org.eclipse.jetty.client.util.InputStreamResponseListener$Input.read(InputStreamResponseListener.java:313) at org.eclipse.jetty.util.IO.copy(IO.java:172) at org.eclipse.jetty.util.IO.copy(IO.java:122) at
...
..
`
httpClient = new HttpClient(new SslContextFactory());
httpClient.setConnectTimeout(60000);
httpClient.setIdleTimeout(60000);
httpClient.setStopTimeout(60000);
httpClient.setAddressResolutionTimeout(60000);
httpClient.setMaxConnectionsPerDestination(1024);
httpClient.setMaxRequestsQueuedPerDestination(1024);
httpClient.start();

Request request = httpClient.newRequest(xmlUrl);
InputStreamResponseListener listener = new InputStreamResponseListener();

request.send(listener);
Response contentResponse = listener.get(180, TimeUnit.SECONDS);

if (contentResponse.getStatus() == 200) {
try (InputStream inputStream = listener.getInputStream();
OutputStream outputStream = Files.newOutputStream(tmpFile)) {
IO.copy(inputStream, outputStream);
}
}
`

[josepowera]

we also found this in logs:

java.lang.IllegalStateException: Invalid response state TRANSIENT at org.eclipse.jetty.client.HttpReceiver$Decoder.resume(HttpReceiver.java:841) at org.eclipse.jetty.client.HttpReceiver$Decoder.access$000(HttpReceiver.java:766) at org.eclipse.jetty.client.HttpReceiver.demand(HttpReceiver.java:116) at org.eclipse.jetty.client.HttpReceiver$ContentListeners.demand(HttpReceiver.java:723) at org.eclipse.jetty.client.ResponseNotifier.lambda$notifyContent$1(ResponseNotifier.java:139) at org.eclipse.jetty.client.api.Response$AsyncContentListener.lambda$onContent$0(Response.java:192) at org.eclipse.jetty.util.Callback$3.succeeded(Callback.java:129) at org.eclipse.jetty.client.util.InputStreamResponseListener$Input.read(InputStreamResponseListener.java:331) ... 8 more

fyi:
downloaded file is xml, we download using http, file has approx size of ~21MB. File was not compressed on server ( no .gz)

[sbordet]

@josepowera are you sure that the file is not gzipped?

The stack trace shows the client is in Decoder.resume(), which is invoked only if there is decoding to do.

[sbordet]

@mperktold can you please describe how do you read the response content? Do you also use InputStreamResponseListener?

[sbordet]

I was able to reproduce the issue, working on a fix.

[mperktold]

Great to hear! 👍

In case you still want to know, yes, we also use InputStreamResponseListener in this case.

[josepowera]

@sbordet

Hi. I checked the file regarding gzip... The file on server is not gziped. But when we download it using chrome we see that server or cloudflare as proxy has dynamically gziped file for chrome.

[joakime]

@josephca is the file compressed with gzip and sent normally, or is the content-encoding on the http headers set to gzip and the body contents are sent gzipped? (small nuance, but it makes a difference)

[josepowera]

@joakime

These are headers from chrome... I also sent link to DL link we have problems with to @sbordet via email. The file on server in filesystem is not gzipped.

Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: *
CF-Cache-Status: DYNAMIC
CF-RAY: 5e1becccea25fc6d-ZAG
cf-request-id: 05c55254130000fc6d2934b200000001
Content-Encoding: gzip
Content-Type: application/xml
Date: Tue, 13 Oct 2020 20:49:03 GMT
Last-Modified: Wed, 27 Nov 2019 12:18:21 GMT
NEL: {"report_to":"cf-nel","max_age":604800}
Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report?lkg-colo=124&lkg-time=1602622144"}],"group":"cf-nel","max_age":604800}
Server: cloudflare

[joakime]

Interesting, I see no Content-Length or Transfer-Encoding: chunked on those responses headers.

But that would mean the response must contain a Connection: close header to satisfy the transfer of the body content.
In other words, point 7 on "Message Body Length" in Section 3.3.3 on the HTTP/1.1 spec (https://tools.ietf.org/html/rfc7230#section-3.3.3)

[sbordet]

@mperktold @josepowera are you able to build branch jetty-9.4.x-5409-invalid_response_state_transient to verify the fix?

[mperktold]

Yes, I was able to build the branch, thanks. We will now deploy it for a while to verify.

[mperktold]

We deployed the branch to production for a few days and the problem has not appeared since then.
Previously, there were multiple failures per day.

So the problem seems to be fixed 👍

[sbordet]

@mperktold thanks for the feedback!

We are about to release Jetty 9.4.33 this week, so you will be able to upgrade soon.