[jetty-dev] jetty 9.4.4 with http2 enabled produces many "idletimeout" exceptions

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

[jetty-dev] jetty 9.4.4 with http2 enabled produces many "idletimeout" exceptions

Michele Rossi
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 <[hidden email]>
Date: 10 November 2016 at 14:38
Subject: issue with libcurl/7.50.3 and http2 with multipart upload request?
To: [hidden email], Simone Bordet <[hidden email]>


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 <[hidden email]>
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 <[hidden email]>
Cc: "Jetty @ Eclipse developer discussion list" <[hidden email]>, Simone Bordet <[hidden email]>


Hi,

On Tue, Nov 8, 2016 at 12:32 PM, Michele Rossi <[hidden email]> 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.



_______________________________________________
jetty-dev mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev

http2-upload-error.zip (257K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: [jetty-dev] jetty 9.4.4 with http2 enabled produces many "idletimeout" exceptions

Simone Bordet-3
Hi,

On Tue, May 2, 2017 at 11:22 AM, Michele Rossi <[hidden email]> wrote:
> 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

[snip]

> 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.

Well, if you can confirm that this is again the case would be great.

> 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'm not sure there is a simple way.

If the client says it will send more content, but then it does not,
there is not much that the server can do apart timeout.

Even assuming you can identify a misbehaving client, what would you do ?
Discard every request it makes ? Wait a bit and then assume it sent
the whole content ?

In any case perhaps this logic can be implemented in the application.

Easier solution would be to use good clients. Can you use Jetty's HttpClient ?

--
Simone Bordet
----
http://cometd.org
http://webtide.com
Developer advice, training, services and support
from the Jetty & CometD experts.
_______________________________________________
jetty-dev mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev
Reply | Threaded
Open this post in threaded view
|

Re: [jetty-dev] jetty 9.4.4 with http2 enabled produces many "idletimeout" exceptions

Michele Rossi
hi Simone,

> Wait a bit and then assume it sent the whole content ?

Yeah, I was thinking something along those lines - sounds like a hack but coupled with checks on the user agent it could be acceptable :)



> Easier solution would be to use good clients. Can you use Jetty's HttpClient ?

No, unfortunately in our company we have several teams working on different products using different technologies and when they choose to integrate with my system they can do what they want using whatever technology they fancy.

However in this case as well as in the old Timeout case it looks like we are dealing with CURL.

I can try to re-enable low-level HTTP logging to see if we get any evidence of misbehavior again.


thanks,
Michele





On 2 May 2017 at 11:42, Simone Bordet <[hidden email]> wrote:
Hi,

On Tue, May 2, 2017 at 11:22 AM, Michele Rossi <[hidden email]> wrote:
> 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

[snip]

> 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.

Well, if you can confirm that this is again the case would be great.

> 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'm not sure there is a simple way.

If the client says it will send more content, but then it does not,
there is not much that the server can do apart timeout.

Even assuming you can identify a misbehaving client, what would you do ?
Discard every request it makes ? Wait a bit and then assume it sent
the whole content ?

In any case perhaps this logic can be implemented in the application.

Easier solution would be to use good clients. Can you use Jetty's HttpClient ?

--
Simone Bordet
----
http://cometd.org
http://webtide.com
Developer advice, training, services and support
from the Jetty & CometD experts.
_______________________________________________
jetty-dev mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev


_______________________________________________
jetty-dev mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev
Reply | Threaded
Open this post in threaded view
|

Re: [jetty-dev] jetty 9.4.4 with http2 enabled produces many "idletimeout" exceptions

Simone Bordet-3
Hi,

On Tue, May 2, 2017 at 11:59 AM, Michele Rossi <[hidden email]> wrote:
> However in this case as well as in the old Timeout case it looks like we are
> dealing with CURL.

What exact version ?
cURL developer, @bagder, is pretty active on Twitter.
I doubt he would leave such bug unattended.

Perhaps it's just matter to update your cURL version ?

--
Simone Bordet
----
http://cometd.org
http://webtide.com
Developer advice, training, services and support
from the Jetty & CometD experts.
_______________________________________________
jetty-dev mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-dev