-----Original Message-----
From: Sievers, Jan
Sent: Montag, 1. Juni 2015 11:31
To: 'cf-dev(a)lists.cloudfoundry.org'
Subject: sporadic connection resets between login and uaa

Hi,

while running the CF 207 smoke and acceptance tests repeatedly, we noticed
sporadic connection resets during 'cf login'
(see log snippet from login log below).

The connection reset is happening on the login machine when it's doing an
HTTP POST to

http://uaa.cf.<DOMAIN>/authenticate

(via load balancer, and getting a connection reset from the load balancer).
This is happening ~ 1 out of 5 times if we run the smoke tests every 5
minutes.

We found that adding

-Dhttp.keepAlive=false

to JAVA_OPTS in /var/vcap/jobs/login/bin/login_ctl

works around the problem. Otherwise, by default there is a pool of 5
connections being kept alive and reused.

We use an F5 BigIP load balancer with 300 seconds socket idle timeout
configured.

Could this be a bug with stale connections being reused by the HTTP client on
the login machine?

Best Regards,
Jan


--- log snippet from login machine ---

[2015-05-08 08:07:52.787] login - 9054 [http-bio-8080-exec-2] .... DEBUG ---
DispatcherServlet: DispatcherServlet with name 'spring' processing POST
request for [/error500]
[2015-05-08 08:07:52.787] login - 9054 [http-bio-8080-exec-2] .... DEBUG ---
RequestMappingHandlerMapping: Looking up handler method for path /error500
[2015-05-08 08:07:52.787] login - 9054 [http-bio-8080-exec-2] .... DEBUG ---
RequestMappingHandlerMapping: Returning handler method [public
java.lang.String
org.cloudfoundry.identity.uaa.login.HomeController.error500(org.springframewo
rk.ui.Model,javax.servlet.http.HttpServletRequest)]
[2015-05-08 08:07:52.787] login - 9054 [http-bio-8080-exec-2] .... ERROR ---
HomeController: Internal error
org.springframework.web.client.ResourceAccessException: I/O error on POST
request for "http://uaa.cf.<DOMAIN>/authenticate":Connection reset; nested
exception is java.net.SocketException: Connection reset
at
org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:567)
at
org.springframework.security.oauth2.client.OAuth2RestTemplate.doExecute(OAuth
2RestTemplate.java:128)
at
org.springframework.web.client.RestTemplate.execute(RestTemplate.java:512)
at
org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:454)
at
org.cloudfoundry.identity.uaa.login.RemoteUaaAuthenticationManager.authentica
te(RemoteUaaAuthenticationManager.java:137)
at
org.cloudfoundry.identity.uaa.authentication.AuthzAuthenticationFilter.doFilt
er(AuthzAuthenticationFilter.java:138)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter
(FilterChainProxy.java:342)
at
org.springframework.security.web.context.request.async.WebAsyncManagerIntegra
tionFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFi
lter.java:107)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter
(FilterChainProxy.java:342)
at
org.springframework.security.web.context.SecurityContextPersistenceFilter.doF
ilter(SecurityContextPersistenceFilter.java:87)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter
(FilterChainProxy.java:342)
at
org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChai
nProxy.java:192)
at
org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.j
ava:160)
at
org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(Delegatin
gFilterProxy.java:344)
at
org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilte
rProxy.java:261)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationF
ilterChain.java:241)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterCha
in.java:208)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.jav
a:220)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.jav
a:122)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.
java:501)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
at
org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:683)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:
116)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:
116) [37/1995]
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Proces
sor.java:1070)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(Abstract
Protocol.java:611)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:3
14)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:114
5)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:61
5)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.jav
a:61)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:196)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at
org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferI
mpl.java:136)
at
org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferI
mpl.java:152)
at
org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImp
l.java:270)
at
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResp
onseParser.java:140)
at
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResp
onseParser.java:57)
at
org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.jav
a:260)
at
org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(Defau
ltBHttpClientConnection.java:161)
at sun.reflect.GeneratedMethodAccessor121.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.
java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.http.impl.conn.CPoolProxy.invoke(CPoolProxy.java:138)
at com.sun.proxy.$Proxy45.receiveResponseHeader(Unknown Source)
at
org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExe
cutor.java:271)
at
org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java
:123)
at
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:254
)
at
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)
at
org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
at
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)
at
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.j
ava:186)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.j
ava:82)
at
org.springframework.http.client.HttpComponentsClientHttpRequest.executeIntern
al(HttpComponentsClientHttpRequest.java:91)
at
org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInt
ernal(AbstractBufferingClientHttpRequest.java:48)
at
org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractCli
entHttpRequest.java:53)
at
org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:551)
... 33 more

Am I right this problem is obsolete since the login-uaa merge in CF 208
[1]?

Regards,
Jan

[1] http://lists.cloudfoundry.org/pipermail/cf-dev/2015-May/000087.html

-----Original Message-----
From: Sievers, Jan
Sent: Montag, 1. Juni 2015 11:31
To: 'cf-dev(a)lists.cloudfoundry.org'
Subject: sporadic connection resets between login and uaa

Hi,

while running the CF 207 smoke and acceptance tests repeatedly, we

noticed

sporadic connection resets during 'cf login'
(see log snippet from login log below).

The connection reset is happening on the login machine when it's doing an
HTTP POST to

http://uaa.cf.<DOMAIN>/authenticate

(via load balancer, and getting a connection reset from the load

balancer).

This is happening ~ 1 out of 5 times if we run the smoke tests every 5
minutes.

We found that adding

-Dhttp.keepAlive=false

to JAVA_OPTS in /var/vcap/jobs/login/bin/login_ctl

works around the problem. Otherwise, by default there is a pool of 5
connections being kept alive and reused.

We use an F5 BigIP load balancer with 300 seconds socket idle timeout
configured.

Could this be a bug with stale connections being reused by the HTTP

client on

the login machine?

Best Regards,
Jan


--- log snippet from login machine ---

[2015-05-08 08:07:52.787] login - 9054 [http-bio-8080-exec-2] .... DEBUG

---

DispatcherServlet: DispatcherServlet with name 'spring' processing POST
request for [/error500]
[2015-05-08 08:07:52.787] login - 9054 [http-bio-8080-exec-2] .... DEBUG

---

RequestMappingHandlerMapping: Looking up handler method for path

/error500

[2015-05-08 08:07:52.787] login - 9054 [http-bio-8080-exec-2] .... DEBUG

---

RequestMappingHandlerMapping: Returning handler method [public
java.lang.String

org.cloudfoundry.identity.uaa.login.HomeController.error500(org.springframewo

rk.ui.Model,javax.servlet.http.HttpServletRequest)]
[2015-05-08 08:07:52.787] login - 9054 [http-bio-8080-exec-2] .... ERROR

---

HomeController: Internal error
org.springframework.web.client.ResourceAccessException: I/O error on POST
request for "http://uaa.cf.<DOMAIN>/authenticate":Connection reset;

nested

exception is java.net.SocketException: Connection reset
at

org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:567)

at

org.springframework.security.oauth2.client.OAuth2RestTemplate.doExecute(OAuth

2RestTemplate.java:128)
at

org.springframework.web.client.RestTemplate.execute(RestTemplate.java:512)

at

org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:454)

at

org.cloudfoundry.identity.uaa.login.RemoteUaaAuthenticationManager.authentica

te(RemoteUaaAuthenticationManager.java:137)
at

org.cloudfoundry.identity.uaa.authentication.AuthzAuthenticationFilter.doFilt

er(AuthzAuthenticationFilter.java:138)
at

org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter

(FilterChainProxy.java:342)
at

org.springframework.security.web.context.request.async.WebAsyncManagerIntegra

tionFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50)
at

org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFi

lter.java:107)
at

org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter

(FilterChainProxy.java:342)
at

org.springframework.security.web.context.SecurityContextPersistenceFilter.doF

ilter(SecurityContextPersistenceFilter.java:87)
at

org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter

(FilterChainProxy.java:342)
at

org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChai

nProxy.java:192)
at

org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.j

ava:160)
at

org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(Delegatin

gFilterProxy.java:344)
at

org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilte

rProxy.java:261)
at

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationF

ilterChain.java:241)
at

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterCha

in.java:208)
at

org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.jav

a:220)
at

org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.jav

a:122)
at

org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.

java:501)
at

org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)

at

org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)

at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
at
org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:683)
at

org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:

116)
at

org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)

at

org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:

116) [37/1995]
at

org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)

at

org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Proces

sor.java:1070)
at

org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(Abstract

Protocol.java:611)
at

org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:3

14)
at

java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:114

5)
at

java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:61

5)
at

org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.jav

a:61)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:196)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at

org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferI

mpl.java:136)
at

org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferI

mpl.java:152)
at

org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImp

l.java:270)
at

org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResp

onseParser.java:140)
at

org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResp

onseParser.java:57)
at

org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.jav

a:260)
at

org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(Defau

ltBHttpClientConnection.java:161)
at sun.reflect.GeneratedMethodAccessor121.invoke(Unknown Source)
at

sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.

java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at

org.apache.http.impl.conn.CPoolProxy.invoke(CPoolProxy.java:138)

at com.sun.proxy.$Proxy45.receiveResponseHeader(Unknown Source)
at

org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExe

cutor.java:271)
at

org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java

:123)
at

org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:254

)
at

org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)

at
org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
at

org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)

at

org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.j

ava:186)
at

org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.j

ava:82)
at

org.springframework.http.client.HttpComponentsClientHttpRequest.executeIntern

al(HttpComponentsClientHttpRequest.java:91)
at

org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInt

ernal(AbstractBufferingClientHttpRequest.java:48)
at

org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractCli

entHttpRequest.java:53)
at

org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:551)

... 33 more

_______________________________________________
cf-dev mailing list
cf-dev(a)lists.cloudfoundry.org
https://lists.cloudfoundry.org/mailman/listinfo/cf-dev