|
|
留胡子的花生
3 年前 |
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 accountWe use Spring Cloud Gateway with Spring Security OAuth2.
SpringBoot version: 2.2.1
Spring Cloud version: Hoxton.Release
Netty: reactor-netty-0.9.2.RELEASE
The Spring security OAuth2 filter post request to UAA server, there is load balancer in between. While initially connection all good but after about 10-15 min, Netty used Spring OAuth2 filter got connection reset by peer and the other end is load balancer. If try again, then it will work. But after another 10-15 min, the problem happens again.
The log shows reactor.netty.resources.PooledConnectionProvider uses some active channel but it is actually not active. We are seeking solution to work around it. So far we tried
to customize Netty ClientHttpConnector (code as below) to disable pool, but no success. It seems that bean has no effect on Netty used by Spring security.
I uploaded demo project at GitHub link below,
spring-cloud/spring-cloud-gateway#1493
That project cannot produce problem at local as there is no load balancer between but it shows the way to customize ClientHttpConnector used by Spring Security to disable Netty Pool does not work.
@bean
public ClientHttpConnector clientHttpConnector() {
return new ReactorClientHttpConnector(HttpClient.create(ConnectionProvider.newConnection()));
From Netty side, is there any solution or work around to this issue? Since our project is due soon in production, any work around we are considering. If you could point out where in Netty code, we can disable the pool as a temporary solutions so that we can move forward and revisit this issue later on.
Here is the logs:
2019-12-19 18:07:53.460 DEBUG 7 --- [reactor-http-epoll-1] o.s.w.r.f.client.ExchangeFunctions : [1b45ced7] HTTP POST https://server-name/oauth/token
2019-12-19 18:07:53.462 DEBUG 7 --- [reactor-http-epoll-4] r.n.resources.PooledConnectionProvider : [id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 - R:xxx.xxx.xxx.xxx:443] Channel acquired, now 1 active connections and 1 inactive connections
2019-12-19 18:07:53.463 DEBUG 7 --- [reactor-http-epoll-4] r.netty.http.client.HttpClientConnect : [id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 - R:xxx.xxx.xxx.xxx:443] Handler is being applied: {uri=https://server-name/oauth/token, method=POST}
2019-12-19 18:07:53.466 DEBUG 7 --- [reactor-http-epoll-4] o.s.http.codec.FormHttpMessageWriter : [1b45ced7] Writing form fields [grant_type, code, redirect_uri] (content masked)
2019-12-19 18:07:53.471 DEBUG 7 --- [reactor-http-epoll-4] r.n.resources.PooledConnectionProvider : [id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 - R:xxx.xxx.xxx.xxx:443] onStateChange(POST{uri=/oauth/token, connection=PooledConnection{channel=[id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 - R:xxx.xxx.xxx.xxx:443]}}, [request_sent])
2019-12-19 18:07:53.474 DEBUG 7 --- [reactor-http-epoll-4] r.netty.http.client.HttpClientConnect : [id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 - R:xxx.xxx.xxx.xxx:443] The connection observed an error, the request will be retried
io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
2019-12-19 18:07:53.475 DEBUG 7 --- [reactor-http-epoll-4] r.n.resources.PooledConnectionProvider : [id: 0x9bf92ed9, L:/xxx.xxx.xxx.xxx:38600 - R:xxx.xxx.xxx.xxx:443] Channel acquired, now 2 active connections and 0 inactive connections
2019-12-19 18:07:53.476 DEBUG 7 --- [reactor-http-epoll-4] r.netty.http.client.HttpClientConnect : [id: 0x9bf92ed9, L:/xxx.xxx.xxx.xxx:38600 - R:xxx.xxx.xxx.xxx:443] Handler is being applied: {uri=https://server-name/oauth/token, method=POST}
2019-12-19 18:07:53.479 DEBUG 7 --- [reactor-http-epoll-4] o.s.http.codec.FormHttpMessageWriter : [1b45ced7] Writing form fields [grant_type, code, redirect_uri] (content masked)
2019-12-19 18:07:53.492 DEBUG 7 --- [reactor-http-epoll-4] r.n.resources.PooledConnectionProvider : [id: 0x9bf92ed9, L:/xxx.xxx.xxx.xxx:38600 - R:xxx.xxx.xxx.xxx:443] onStateChange(POST{uri=/oauth/token, connection=PooledConnection{channel=[id: 0x9bf92ed9, L:/xxx.xxx.xxx.xxx:38600 - R:xxx.xxx.xxx.xxx:443]}}, [request_sent])
2019-12-19 18:07:53.507 DEBUG 7 --- [reactor-http-epoll-4] r.n.resources.PooledConnectionProvider : [id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 ! R:xxx.xxx.xxx.xxx:443] Channel closed, now 2 active connections and 0 inactive connections
2019-12-19 18:07:53.517 DEBUG 7 --- [reactor-http-epoll-4] r.n.resources.PooledConnectionProvider : [id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 ! R:xxx.xxx.xxx.xxx:443] onStateChange(POST{uri=/oauth/token, connection=PooledConnection{channel=[id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 ! R:xxx.xxx.xxx.xxx:443]}}, [disconnecting])
2019-12-19 18:07:53.518 DEBUG 7 --- [reactor-http-epoll-4] r.n.resources.PooledConnectionProvider : [id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 ! R:xxx.xxx.xxx.xxx:443] Releasing channel
2019-12-19 18:07:53.523 DEBUG 7 --- [reactor-http-epoll-4] r.n.resources.PooledConnectionProvider : [id: 0x2a4d88b0, L:/xxx.xxx.xxx.xxx:38628 ! R:xxx.xxx.xxx.xxx:443] Channel cleaned, now 1 active connections and 0 inactive connections
2019-12-19 18:07:53.532 DEBUG 7 --- [reactor-http-epoll-4] r.netty.http.client.HttpClientConnect : [id: 0x9bf92ed9, L:/xxx.xxx.xxx.xxx:38600 - R:xxx.xxx.xxx.xxx:443] The connection observed an error, the request will be retried
io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
2019-12-19 18:07:53.543 ERROR 7 --- [reactor-http-epoll-4] o.s.w.s.adapter.HttpWebHandlerAdapter : [177851e0] 500 Server Error for HTTP GET "/login/oauth2/code/myapp?code=Jo87
qf1XIC&state=yMYngnlcVyuy8BgpgFGxZDwo0nmwYg7pa4mcvROTtrU%3D"
io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException:
Error has been observed at the following site(s):
|_ checkpoint Request to POST https://server-name/oauth/token [DefaultWebClient]
|_ checkpoint org.springframework.security.oauth2.client.web.server.authentication.OAuth2LoginAuthenticationWebFilter [DefaultWebFilterChain]
Thanks for looking into this issue. Due to constraints, I am not sure if I am allowed to send the TCP dump. The application is deployed in cloud. Between our application and IDP server which application try to Post request to, there is AWS load Balancer (LB). The LB usually drops connection in 15 min idle. There is not much we can do at this point.
The log already clearly shows Peer resets connection which is LB.
2019-12-19 18:07:53.532 DEBUG 7 --- [reactor-http-epoll-4] r.netty.http.client.HttpClientConnect : [id: 0x9bf92ed9, L:/(Our app server IP address):38600 - R:(Load balancer IP address):443] The connection observed an error, the request will be retried
io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
The issue here is that how Netty Pool health check working, every 5 min, 30 min, etc? What kind of algorithm to do recovery? When connection get reset, I do see Netty retries 2-3 times by picking up the connection from pool, however, usually for this case, LB drop idle connection, they could drop all the connections in the pool which are idle. So retry never works.
I am think if Netty could improve its algorithm, if one connection bad, then dispose it and create new connection instead of picking up from pool once again, after that put that new connection into pool.
Our application is nearly in PROD and we are pending on the workaround or fix on this issue. Is it possible for Netty to have a quick patch or make a temp release to work around this issue so we can move forward and revisit this issue later on?
We tried disable Netty connection Pool, however Spring security creates its own webclient, not our application, and we tried different ways to customize it but no effective.
I uploaded demo project at GitHub link below to show the ways we try to disable the Netty Pool
spring-cloud/spring-cloud-gateway#1493
but so far nothing works.
So again Netty is a wonderful lib and Spring Cloud Gateway/WebFlux leverage on it. But when more and more applications leverage those technologies goes to PROD, especially to cloud, most of them will face load balancing and this issue will impact Netty in long run if all those applications have to disable pool or set HTTP_LIVE false or manipulate the timeout at application level.
@hanscrg We check the health of the connection before using it
https://github.com/reactor/reactor-netty/blob/master/src/main/java/reactor/netty/resources/ConnectionProvider.java#L198
https://github.com/reactor/reactor-netty/blob/master/src/main/java/reactor/netty/resources/PooledConnectionProvider.java#L218
See the eviction predicate.
A connection that is closed, idle more than the specified time or have life more that specified time will be evicted.
If you cannot provide TCP dump then you can check it by yourself - when exactly the connection is closed.
From the logs above I can clearly see that the connection was ok at the beginning.
The LB usually drops connection in 15 min idle.
This can happen between our acquiring of the connection and sending the request.
By default there is neither idle timeout nor life time. So you have to configure them.
We retry only once when such issue happens, but the component that uses Reactor Netty may apply other strategy for retrying such issues (for example retry with backoff).
Also from the logs above I see the following:
Channels with id 0x2a4d88b0 && 0x9bf92ed9 are retried
Channel with id 177851e0 has 500 ISE no more information from the provided logs
Channel with id 1b45ced7 has successful communication
Please note that everything is non-blocking so that you cannot correlate using thread id, because of that you have to use the channel id.
@violetagg,
Thanks for looking into this issue. I will see if I could send out TCP dump. Question is what is gap in time when Netty checks the connection health and using that connection to send http request?
If Netty by default no idle timeout and life time. Then if Spring Security using Reactor Netty HTTP Client does not set those parameters, then the connection will be there all the time and for sure it will be disconnected by Load Balancer.
As I previously mentioned, retry by picking up the existing connection in the pool has a big risk that may have been disconnected also that makes retry not work most of time. I can see many reports on Netty connection reset, which most likely is due to load balancer or something in between drops connection. For some of the applications they have control on the Netty HTTP Client, they can apply different ways to recover. But for Spring applications leverage Spring Security, it creates HTTP Client on its own and the application do not have much control. Maybe Netty could optimize its recovery algorithm for this case, when doing retry, create new connection instead of reuse one in the pool.
I will update you more info when I look into our logs or if I can send TCP dump.
If Netty by default no idle timeout and life time. Then if Spring Security using Reactor Netty HTTP Client does not set those parameters
They can expose a configuration. I think that if you have the configuration above you will be able to solve your use case. If that's not the case we can think of exposing an API for specifying the eviction.
But for Spring applications leverage Spring Security, it creates HTTP Client on its own and the application do not have much control.
There are different retry strategies (also have in mind that we retry only when there is Connection reset by peer) so I prefer the components (especially those working with sensitive data) that use Reactor Netty to define the retry functionality based on the strategy that they want and the exceptions that they want to handle.
Did you check Spring Security samples https://github.com/spring-projects/spring-security/tree/master/samples/boot/oauth2webclient-webflux
or this type of configuration is not sufficient for your use case?
@violetagg
Thanks for the response. From the feedback from Spring Cloud Gateway, there is no configuration that works at their side as the WebClient is created in Spring Security and I have not get feedback from Spring Security yet. The Spring Security samples at the link above I looked through and does not find the way to customize the WebClient or ClientHTTPConnection which Spring Security uses. Also disable connection pool anyway is really a workaround and not the perfect solution even we can get it working.
I think the retry strategies should be implemented at the lower level which is Reactor Netty. Netty can define different strategies for example, Reuse First then New or New Only or Reuse Only, etc, by default Reuse First then New. WebClient or higher level components or lib which uses Netty has the option to choose the retry strategies based on their focus either on reliability or efficiency.
For applications moving to cloud or any application has load balancer which leverages Spring Security, this issue will become outstanding, I believe. I saw many posts which try different ways to work around it, disable pool, set HTTP_LIVE false, switch to undertow, set builder to native or tuning timeout parameters or even update their load balancing algorithm. That is not the situation which Netty want to see. Please consider a quick patch or fix if possible.
Meanwhile I am still checking with our management to see if I could get approval to send out TCPDump. If Netty has patch or fix, we can help to test it as soon as possible.
I believe this is still occurring under:
SpringBoot version: 2.2.2
Spring Cloud version: Hoxton.SR1
Netty: reactor-netty-0.9.2.RELEASE
Is there a better strategy to prevent the this? I concur with the complication that Spring Security introduces. The configuration is not exposed so the default behavior of Netty should be updated to in Netty (actually for any api that wraps Netty).
@hanscrg did you find a better way to handle this?
@odbuser2, I tried boot 2.2.2 and Hoxton.SR1, the issue is still there. Actually the root of issue is Netty connection pool in Spring Security. Once the connection(channel) in pool dropped by network components after idle time 15min (very possible no RST send out), all the idle connections in pool do not work which Netty does not detect until it try to reuse the connection. Either Spring Security need to expose the HTTP Client configuration so we can disable the pool or Netty need to enhance the connection pool retry algorithm. I think disable pool is just a workaround even if Spring Security has such way which I do not find yet. The perfect solution is Netty enhance the retry algorithm.
With more API wraps Netty and connection pool is used, this issue will be more outstanding.
For us there is no better way to handle it, we just did some workaround at our application level to catch the exception and resend the request. We are still waiting for Netty to give a solution or Spring security to expose some way to disable its connection pool.
@hanscrg @odbuser2 The proper way is Spring Security to provide a way for configuring the HttpClient (as it can be done in Spring Gateway)
However what do you think if Reactor Netty adds a system property for the idle timeout? Similar to acquire timeout - https://github.com/reactor/reactor-netty/blob/master/src/main/java/reactor/netty/ReactorNetty.java#L119
With a system property you will be able to specify the idle timeout outside of the component that uses Reactor Netty.
We are going to expose a configuration property for switching pool's lease strategy from FIFO to LIFO (FIFO is by default) #962
Using LIFO leasing strategy + max idle timeout will give you the behaviour that you need
When the connection is acquired it will be the most recently used
If max idle timeout is reached this means that this connection will be closed and as this connection was the most recently used this means that all the rest (those that are not active) in the pool will also be closed because of the max idle timeout. A new connection will be created and used for the request.
If the connection is closed by the remote peer between acquire and the actual usage - Connection reset by peer will be received and we will retry the request. As this connection was the most recently used and it was closed by the remote peer this mean all the rest (those that are not active) in the pool also will be closed thus again a new connection will be used for the second attempt.
@violetagg, thanks for the feedback. LIFO leasing strategy + Max idle timeout sounds a good solution to this issue which will eventually make Netty client more robust to connection drop by the network components due to their idle timeout setting. The question is in our case our application leverages Spring Security, Spring Security use Netty Client. if Netty exposes configuration property for leasing strategy and MAX Idle Timeout in environment variables or system properties, our application set them accordingly, assuming worst case Spring security also set those configurations in their lib and does not expose those setting. then what is the order of precedence Netty takes?
The configuration will be available in 0.9.5 -> #962
If Spring Security exposes a configuration I would expect that user's configuration to be taken into consideration.
Do you still need these configurations as system properties?
The properties are provided with commit a68ac6e
* Default max idle time, fallback - max idle time is not specified.
public static final String POOL_MAX_IDLE_TIME = "reactor.netty.pool.maxIdleTime";
* Default leasing strategy (fifo, lifo), fallback to fifo.
* <li>fifo - The connection selection is first in, first out</li>
* <li>lifo - The connection selection is last in, first out</li>
* </ul>
public static final String POOL_LEASING_STRATEGY = "reactor.netty.pool.leasingStrategy";
@violetagg, Thanks for the update. What release will have this enhancement? For the application which does not directly create Netty HTTP client (Spring Security does it in our case and it may not expose this configuration), how we set the POOL_LEASING_STRATEGY in our application? For cloud application, environment variable is our preference. Is it possible to set this configuration as environment variable?
@hanscrg opened an issue in spring-security to set these properties but it was declined. Spring-boot should be updated to use these properties.
spring-projects/spring-security#7985
@violetagg, I tried to start Spring boot application with arguments like
... org.springframework.boot.loader.JarLauncher -Dreactor.netty.pool.maxIdleTime=60000 -Dreactor.netty.pool.leasingStrategy=lifo
it does not seems to take effective on the Netty HTTP client created by Spring Security. The above mentioned issue is still there. How can we tell Netty actually does set leasingStrategy to lifo?
@violetagg , Yes, there are logs like below,
09:43:42.972: [reactor-http-epoll-11] DEBUG r.n.r.PooledConnectionProvider:254 - Creating a new client pool [PoolFactory {maxConnections=500, pendingAcquireMaxCount=-1, pendingAcquireTimeout=45000, maxIdleTime=-1, maxLifeTime=-1, metricsEnabled=false}] for [xxx:443]
Still failed after 2nd retry,
09:55:41.510: [APP/PROC/WEB.0] 13:55:41.509 [reactor-http-epoll-12] DEBUG r.n.http.client.HttpClientConnect:259 - [id: 0xbca8464a, L:/xxx.xxx.xxx.xxx:42074 - R: xxx.xxx.xxx.xxx:443] The connection observed an error, the request will be retried
09:55:41.510: [APP/PROC/WEB.0] io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
09:55:41.510: [APP/PROC/WEB.0] 13:55:41.510 [reactor-http-epoll-12] DEBUG r.n.r.PooledConnectionProvider:254 - [id: 0xa7674bf8, L:/xxx.xxx.xxx.xxx:42074 - R: xxx.xxx.xxx.xxx:443] Channel acquired, now 2 active connections and 0 inactive connections
09:55:41.511: [APP/PROC/WEB.0] 13:55:41.510 [reactor-http-epoll-12] DEBUG r.n.http.client.HttpClientConnect:254 - [id: 0xa7674bf8, L:/xxx.xxx.xxx.xxx:42074 - R: xxx.xxx.xxx.xxx:443] Handler is being applied: {uri=https://xxx.xxx/oauth/token, method=POST}
09:55:41.517: [APP/PROC/WEB.0] io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer
09:55:41.517: [APP/PROC/WEB.0] Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException:
09:55:41.517: [APP/PROC/WEB.0] Error has been observed at the following site(s):
09:55:41.517: [APP/PROC/WEB.0] |_ checkpoint Request to POST https://xxx.xxx/oauth/token [DefaultWebClient]
09:55:41.517: [APP/PROC/WEB.0] |_ checkpoint org.springframework.security.oauth2.client.web.server.authentication.OAuth2LoginAuthenticationWebFilter [DefaultWebFilterChain]
09:55:41.517: [APP/PROC/WEB.0] |_ checkpoint org.springframework.security.oauth2.client.web.server.OAuth2AuthorizationRequestRedirectWebFilter [DefaultWebFilterChain]
@violetagg, yes, it is a SpringBoot application deployed to cloud foundry. The manifest already set the Java exec command arguments as below,
JBP_CONFIG_JAVA_MAIN: '{ arguments: "-Dreactor.netty.pool.maxIdleTime=60000 -Dreactor.netty.pool.leasingStrategy=lifo" }'
Also the output message from application launch does show
org.springframework.boot.loader.JarLauncher -Dreactor.netty.pool.maxIdleTime=60000
-Dreactor.netty.pool.leasingStrategy=lifo
Just checked System properties and looks like not there. Let me try other alternative.
I printed out the system properties right before SpringApplication.run(), the system properties does get set as below, but somehow it does not take effective in Netty HTTP Client created by Spring Security.
12:10:18.516: [APP/PROC/WEB.0] -- listing properties --
12:10:18.472: [APP/PROC/WEB.1] reactor.netty.pool.maxIdleTime=60000
@violetagg, I put a very simple demo project at github below,
https://github.com/hanscrg/Sample-SpringCloudGateway-Netty
It is self contained and can be compiled and run easily with the instruction on the project page. The Netty system properties are defined in build.gradle of gateway project and also printed out before SpringApplication.run() on stdout. Could you please review why Netty does not take the two customized system properties?
@hanscrg Can you try 0.9.7.BUILD-SNAPSHOT there was an issue with the default configuration in 0.9.x
Fixed with c6a4f79
Add a system property for the lifetime timeout, similar to idle timeout and acquire timeout
#1232
@violetagg Sorry for mentioning from already closed issue, but I have a question.
Is the default retry "once" bahavior of HttpClient still applied when 'maxIdleTime' has passed since the connection acquired from the pool was lastly used, or it keeps trying to acquire connections until it finds a connection less than 'maxIdleTime' passed from lastly used time or there is no connection left in the pool(create new connection)?
In other words, is default retry once behavior for when the connection is actually used to request server and get error message, not when connection is removed without being used because of 'maxIdleTime'?
@sgc109 Connection doesn't go out of the connection pool if max idle time is reached or this is what happens
or it keeps trying to acquire connections until it finds a connection less than 'maxIdleTime' passed from lastly used time or there is no connection left in the pool(create new connection)
If Netty by default no idle timeout and life time. Then if Spring Security using Reactor Netty HTTP Client does not set those parameters
They can expose a configuration. I think that if you have the configuration above you will be able to solve your use case. If that's not the case we can think of exposing an API for specifying the eviction.
But for Spring applications leverage Spring Security, it creates HTTP Client on its own and the application do not have much control.
There are different retry strategies (also have in mind that we retry only when there is Connection reset by peer) so I prefer the components (especially those working with sensitive data) that use Reactor Netty to define the retry functionality based on the strategy that they want and the exceptions that they want to handle.
Did you check Spring Security samples https://github.com/spring-projects/spring-security/tree/master/samples/boot/oauth2webclient-webflux or this type of configuration is not sufficient for your use case?
I am getting 404 for "https://github.com/spring-projects/spring-security/tree/master/samples/boot/oauth2webclient-webflux". Please share me working directory code.