Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
[jetty-dev] jetty 9.4.4 with http2 enabled produces many "idletimeout" exceptions

hi,

I have recently re-enabled HTTP/2.0 on my Jetty 9.4.4 system and I am now seeing loads of these exceptions:

11:10:47.745|WARN |        o.e.j.s.HttpInput||
java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
        at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:166)
        at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

11:12:03.796|WARN |        o.e.j.s.HttpInput||
java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
        at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:166)
        at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)




I reported a similar problem in the past - back then however it was always in coincidence with large HTTP PUT uploads. Now it does not seem to be the case.

However the reason could well be again that some clients connecting to my systems are outdated and are not playing by the (strict?) rules of HTTP/2.0.

I remember that Simone Bordet helped narrow down the problem to misbehaving clients.

I tried getting in touch with the developers of CURL and libcurl in the past but I didn't get very far.



Since it's likely that those non-compliant clients will stick around out there for a while I am wondering whether it would make sense to make Jetty more tolerant to them.

I wouldn't have a clue on how to do that and whether it's even possible since we are talking about very complex logic implemented in the HTTP/2.0 connector that I obviously don't know very well.

Just wanted to throw the idea out there to see what you guys think..


(See emails below for some history on this)

thanks a lot,
Michele




---------- Forwarded message ----------
From: Michele Rossi <michele.rossi@xxxxxxxxx>
Date: 10 November 2016 at 14:38
Subject: issue with libcurl/7.50.3 and http2 with multipart upload request?
To: curl-library@xxxxxxxxxxxx, Simone Bordet <sbordet@xxxxxxxxxxx>


hello LIBCURL developers,

we have found a problem while trying to perform a multipart HTTP PUT request against an HTTP 2.0 server (Jetty 9.3.14) using HTTR (an R library) which in turn uses libcurl 7.50.3.

See below for the explanation by Simone Bordet (one of the dev leads of the Jetty project).

I am also attaching the original log file although I don't think it makes for an easy read.

Perhaps you will want to check the relevant code in case there is something obvious to fix.

Happy to help with further logs / fiddler images / anything else you might need.

(We have solved the problem by disabling ALPN on LIBCURL).


Many thanks,
Michele


---------- Forwarded message ----------
From: Simone Bordet <sbordet@xxxxxxxxxxx>
Date: 8 November 2016 at 15:47
Subject: Re: [jetty-dev] "no content" timeout exception while upl multipart file on 9.3.12 - 9.3.13 - 9.3.14?
To: Michele Rossi <michele.rossi@xxxxxxxxx>
Cc: "Jetty @ Eclipse developer discussion list" <jetty-dev@xxxxxxxxxxx>, Simone Bordet <sbordet@xxxxxxxxxxx>


Hi,

On Tue, Nov 8, 2016 at 12:32 PM, Michele Rossi <michele.rossi@xxxxxxxxx> wrote:
> hi,
>
> I have enabled the Jetty low-level logs and now HTTP2 negotiations and
> traffic are visible but I am far from understanding what's going on :)
>
> I have attached the logs here in case a good soul out there feels like
> taking a look (if it benefits the project too).
>
> For now we have resolved our problem by disabling HTTP2 on the client making
> this particular multipart upload request.

What client are you using ?

I ask because the logs show that the last DATA frame (line 12305)
arrives with the last 48 bytes that would make the total of 1489449
bytes as specified by the Content-Length, but that DATA frame has
end=false, while it should have end=true.

Because there is no indication that the stream has ended, Jetty waits
for more data from the client until it times out.

In HTTP/2 the framing is done by the end stream flags, not by the fact
that the Content-Length has been reached.

It appears to me a client bug.

--
Simone Bordet
----
http://cometd.org
http://webtide.com
Developer advice, training, services and support
from the Jetty & CometD experts.


Attachment: http2-upload-error.zip
Description: Zip archive


Back to the top