Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Set MaxUsageCount with existing connection pool changing the behavior #5147

Closed
navalgoyal opened this issue Aug 13, 2020 · 14 comments · Fixed by #5187
Closed

Set MaxUsageCount with existing connection pool changing the behavior #5147

navalgoyal opened this issue Aug 13, 2020 · 14 comments · Fixed by #5187
Assignees
Labels

Comments

@navalgoyal
Copy link

navalgoyal commented Aug 13, 2020

Jetty version
9.4.32-SNAPSHOT

Java version
Java 1.8

Question
#4809
I was test the setMaxUsageCount with each connection locally and i found some behavior changes in the existing connection pool implemented in Jetty.

My Configuration is Max connection is set to 3 and Max usage for each connection is 5.

When i use RoundRobinConnectionPool and sending 18 request from client. There is random behavior on client. Some time it create 6 connection and some time it create 5 connection.

As per my understanding for Round Robin Pool, it first create connection till max connection reaches and once max connection reaches it uses same connections in roundrobin fashion but here it is not doing.

Also i am getting following exception:

Caused by: java.nio.channels.AsynchronousCloseException
at org.eclipse.jetty.http2.client.http.HttpConnectionOverHTTP2.close(HttpConnectionOverHTTP2.java:144)
at org.eclipse.jetty.client.HttpDestination.release(HttpDestination.java:445)
at org.eclipse.jetty.http2.client.http.HttpConnectionOverHTTP2.onStreamClosed(HttpConnectionOverHTTP2.java:129)
at org.eclipse.jetty.http2.client.http.HttpChannelOverHTTP2.onStreamClosed(HttpChannelOverHTTP2.java:107)
at org.eclipse.jetty.http2.client.http.HttpReceiverOverHTTP2.onClosed(HttpReceiverOverHTTP2.java:207)
at org.eclipse.jetty.http2.HTTP2Stream.notifyClosed(HTTP2Stream.java:682)
at org.eclipse.jetty.http2.HTTP2Stream.onClose(HTTP2Stream.java:562)
at org.eclipse.jetty.http2.HTTP2Stream.close(HTTP2Stream.java:554)
at org.eclipse.jetty.http2.HTTP2Stream.updateCloseAfterReceived(HTTP2Stream.java:455)
at org.eclipse.jetty.http2.HTTP2Stream.updateClose(HTTP2Stream.java:421)
at org.eclipse.jetty.http2.HTTP2Stream.onData(HTTP2Stream.java:367)
at org.eclipse.jetty.http2.HTTP2Stream.process(HTTP2Stream.java:282)
at org.eclipse.jetty.http2.HTTP2Session.onData(HTTP2Session.java:250)
at org.eclipse.jetty.http2.HTTP2Connection$ParserListener.onData(HTTP2Connection.java:376)
at org.eclipse.jetty.http2.parser.BodyParser.notifyData(BodyParser.java:108)
at org.eclipse.jetty.http2.parser.DataBodyParser.onData(DataBodyParser.java:150)
at org.eclipse.jetty.http2.parser.DataBodyParser.emptyBody(DataBodyParser.java:60)
at org.eclipse.jetty.http2.parser.Parser.parseBody(Parser.java:194)
at org.eclipse.jetty.http2.parser.Parser.parse(Parser.java:127)
at org.eclipse.jetty.http2.HTTP2Connection$HTTP2Producer.produce(HTTP2Connection.java:247)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
at org.eclipse.jetty.http2.HTTP2Connection.produce(HTTP2Connection.java:169)
at org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:124)
at org.eclipse.jetty.http2.HTTP2Connection$FillableCallback.succeeded(HTTP2Connection.java:347)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
... 1 more

same behavior changes i found in the Multiplex Pool as well where previously it was creating connection on the Pending Request, it not it is initially creating connection but not using those connection.

Kindly suggest is there any change in the existing behavior??

@sbordet
Copy link
Contributor

sbordet commented Aug 13, 2020

Can you attach some evidence? DEBUG logs?

We have test cases that shows that maxConnections is never exceeded, so you setting it to 3 and seeing 5-6 connections opened it's not right.

@navalgoyal
Copy link
Author

@sbordet i am not saying that all connection are open. some connection goaway i saw in snoops those might be because of maxUsageCount of connection reached but for roundrobin connection pool behavior should not be random where some time 5 connection or some time 6 connections.

@sbordet
Copy link
Contributor

sbordet commented Aug 13, 2020

@navalgoyal this has been discussed in #5068.

Please have a read there to see whether your case is the same or similar.

If it's different, then let's discuss it further.

@navalgoyal
Copy link
Author

@sbordet #5068 is different where it is using old jetty version: 9.4.24. i am using 9.4.32-SNAPSHOT which is latest code and There is changes in Connection Pool.

i saw some changes in the behavior of connection pool where older roundrobin always sent request in different connection using index but in the new implementation i saw more request are sent to one connection even other connection are available.

For my case i have 3 connection and maxUsage is 5 and sending 18 request means till 15th request first 3 connection should be used and on 16th request new connection should be created. same with 17th and 18th request but it is not happening. some time 17th and 18th request goes to the same connection.

@sbordet
Copy link
Contributor

sbordet commented Aug 13, 2020

@navalgoyal sorry but there is no evidence and not enough information.
If you send the requests one after the other, I bet you get the behavior you want.

If you send the requests concurrently without waiting for responses, then you are in the same case of #5068 and the fact you did not see this behavior before was probably just a case.

@navalgoyal
Copy link
Author

@sbordet i ran same test with old and new algo. in the new algorithm i see the difference in roundrobin and multiplex pool. In the previous roundrobin also if i send 100 request with 5 connection, each connection always serve 20 request even i sent request concurrently but now this behavior is random. Now some connection have more than 20 request where some have less then 20 request.

Similar with multiplex pool, previously if i sent 100 request 1 connection server all the request where in the current implementation it open 5 connection but request is served by only one connection.

Also with this maxUsageCount getting AsynchronousCloseException. please check that as well. Similar issue reported in #4809 and as per your suggestion, should use IdleTimout but here i am getting same error.

@sbordet
Copy link
Contributor

sbordet commented Aug 13, 2020

@navalgoyal you are not detailing your test, so cannot really help you here. What you describe is exactly what's in #5068.
If it is different, it's not enough that you say it, you must provide evidence, for example DEBUG logs or a network trace.

Note that we have also introduced pre-opening of connection, so you can leverage that if you really need more control.

What I think it happens in your case, is that you bomb the client concurrently with many requests, but the connections are not opened yet.
The requests will trigger opening of connections, and how many connections are opened depends on how fast they can be opened, and how fast requests are processed.

If that's not what you're doing, you need to detail clearly what you're doing.

I have double checked and we do create too many connections with the multiplex pool - we fixed this in 26c2d34.

In the previous roundrobin also if i send 100 request with 5 connection, each connection always serve 20 request even i sent request concurrently

We have verified that it was not the case, you have just been lucky.

I don't understand the problem with the maxUsageCount and AsynchronousCloseException?
I believe that you have reached the maxUsageCount and the connection is therefore closed, as expected.

@navalgoyal
Copy link
Author

@sbordet Multiplex pool is now not opening many connection after the fix applied.

my use case is for Round Robin pool is that i want use connection in RoundRobin Fashion. i want maxUsage support as well where once maxUsage reached then connection will not serve any more request and closed sliently.

In my case i have given maxConnection 3 and maxUsage 5 and i am sending 18 request concurrently. So with round robin connection, first 3 connection should serve 15 request and then on 16th, 17th and 18th request should be served by new connections so in network traces we should have 3 closed and 3 opened connection but it is not happening i could see 3 closed and 2 opened connection where 1 connection serve 2 request.

Also with the latest code i have observed that after request it is failed to send request to server.

i am here attaching the DEBUG log of jetty. I am using Jetty Server and Jetty client both in the same where Jetty Server accepting request from other node and then send to the Jetty client which is send request to another Jetty server.

WIth the latest changes i have getting request timeout for request.

logs are below

logs.txt

Once Connection Reaches to the maxUsageCount it should close the connection sliently rather than propagating exception to the application.

@sbordet sbordet self-assigned this Aug 18, 2020
@sbordet
Copy link
Contributor

sbordet commented Aug 18, 2020

I'm working on this and will keep you posted.

sbordet added a commit that referenced this issue Aug 22, 2020
Reworked HTTP/2 release after an exchange is terminated.

Previously, the release was bound to 2 events: onStreamClosed(),
introduced for #2796, and exchangeTerminated().
Unfortunately, if the former happens before the latter and
closes the connection, the latter will see the exchange as
aborted, while in fact it was successful, causing what
reported in #5147, an AsynchronousCloseException.

Now, the release is always performed by the exchangeTerminated()
event. With respect to #2796, the stream is always already
closed by the time the exchangeTerminated() event fires (it
was not before).

Reworked the implementation of RoundRobinConnectionPool using
a lock and aggressively trying to open new connections.

A second fix is related to HttpDestination.release(Connection).
If the connection is closed for e.g. overuse, we need to trigger
the processing of queued requests via send(create: true).

Signed-off-by: Simone Bordet <simone.bordet@gmail.com>
@sbordet sbordet linked a pull request Aug 22, 2020 that will close this issue
@sbordet
Copy link
Contributor

sbordet commented Aug 22, 2020

@navalgoyal can you please try branch jetty-9.4.x-5147-h2_round_robin_max_usage and see if it works for you?

sbordet added a commit that referenced this issue Aug 25, 2020
…_max_usage

Issue #5147 - HTTP2 RoundRobinConnectionPool with maxUsage
@sbordet
Copy link
Contributor

sbordet commented Aug 25, 2020

Branch jetty-9.4.x-5147-h2_round_robin_max_usage has been merged to jetty-9.4.x.
@navalgoyal are you able to try the latest code?

@sbordet
Copy link
Contributor

sbordet commented Sep 2, 2020

@navalgoyal news?

@navalgoyal
Copy link
Author

@sbordet i am currently testing it. Will let you know once completed.

@sbordet
Copy link
Contributor

sbordet commented May 5, 2021

Closing as resolved, assuming OP testing was fine.

@sbordet sbordet closed this as completed May 5, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants