[keycloak-user] Wildfly adapter: failed to turn code into token: java.net.SocketException

[Jesse Chahal]

We have been able to reproduce this problem using a single user where we
dedicated 2 wildfly app servers and 1 keycloak server purely to test this
out. We have also been able to reproduce this when trying to use multiple
users as well (but I think the single user scenario is more important). I
believe it may somehow router/network related but I have yet to find a way
to prove it. I don't believe there are any docker network related
limitations in regards to connections. Before this switch we have been
running keycloak in production for awhile as well as the app servers (on
full VM's instead of docker). It is unlikely that the problem exists in any
of our app servers configuration since the configuration is 99% the same.
In the new setup wildfly app servers live in docker (which are based off of
the official jboss wildfly docker images).


Jesse

On Fri, Nov 25, 2016 at 1:01 AM, Marek Posolda <mposolda at redhat.com> wrote:

> Does this happen just if more users tries to login concurrently? It seems
> there is some limit somewhere for the number of maximum connections. Maybe
> it will help to increase maximum number of threads at the undertow
> subsystem on Keycloak side, or maybe at the AWS ELB load balancer side? Or
> maybe there is even some limit at the docker level?
>
> AFAIK The Apache HTTP Client (which is used by our adapters under the hood
> for exchange code to token) has some retry strategy enabled by default.
> AFAIK we don't allow to tweak this, but it's likely 1 or 2 retries for each
> HTTP failed request AFAIK. However this should be rather tweaked by
> increasing the pool of connections for your server. Relying on Apache HTTP
> client retryies doesn't look like good solution IMO.
>
> Marek
>
>
> On 25/11/16 01:48, Jesse Chahal wrote:
>
>> We very recently started working on moving our web/app servers to AWS ECS
>> (docker). We have been using docker locally for a very long time without
>> issues.
>> During this transition we started seeing intermittent login failures
>> through the normal confidential browser redirect flow (not using
>> implicit).
>> It inconsistently fails during the process of turning an authorization
>> code
>> into a bearer+refresh_token. The exception is always the same as well. I
>> have done
>> tcpdumps packet analysis for things such as RST packets but have not seen
>> anything that would result in this issue. I have confirmed that the
>> adapter
>> does
>> have the authorization code (although I don't know how to validate it). I
>> have confirmed that the the date+times are synchronized in both the auth
>> server
>> and the app server (therefore no weird expiration issues).
>> I have posted a stacktrace from the adapter incase anyone else has seen
>> this issue before. I'm hoping at the very least that maybe we could add a
>> retry
>> mechanism to the adapter if a Connection reset issues occurs if no other
>> solutions present themselves.
>>
>> Current network setup:
>> Keycloak.2.1.0.Final on Centos6 EC2/VM --> AWS ELB load balancer -->
>> internet -->
>>
>>       ↓
>>   <---------------------------------------------------------------------
>> -----------
>> ↓
>> AWS NAT Gateway --> AWS ELB load balancer --> Amazon Linux ECS EC2/VM -->
>> Wildfly10 docker container + keycloak 2.1.0-wildfly-adapter
>>
>>
>> ERROR [org.keycloak.adapters.OAuthRequestAuthenticator] (default
>> task-13) [
>>   ] failed to turn code into token: java.net.SocketException: Connection
>> reset
>>          at java.net.SocketInputStream.read(SocketInputStream.java:209)
>> [rt.jar:1.8.0_111]
>>          at java.net.SocketInputStream.read(SocketInputStream.java:141)
>> [rt.jar:1.8.0_111]
>>          at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
>> [jsse.jar:1.8.0_111]
>>          at sun.security.ssl.InputRecord.read(InputRecord.java:503)
>> [jsse.jar:1.8.0_111]
>>          at
>> sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
>> [jsse.jar:1.8.0_111]
>>          at
>> sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
>> [jsse.jar:1.8.0_111]
>>          at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
>> [jsse.jar:1.8.0_111]
>>          at
>> org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffe
>> r(AbstractSessionInputBuffer.java:160)
>>          at
>> org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketI
>> nputBuffer.java:84)
>>          at
>> org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(
>> AbstractSessionInputBuffer.java:273)
>>          at
>> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHea
>> d(DefaultHttpResponseParser.java:140)
>>          at
>> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHea
>> d(DefaultHttpResponseParser.java:57)
>>          at
>> org.apache.http.impl.io.AbstractMessageParser.parse(Abstract
>> MessageParser.java:261)
>>          at
>> org.apache.http.impl.AbstractHttpClientConnection.receiveRes
>> ponseHeader(AbstractHttpClientConnection.java:283)
>>          at
>> org.apache.http.impl.conn.DefaultClientConnection.receiveRes
>> ponseHeader(DefaultClientConnection.java:251)
>>          at
>> org.apache.http.impl.conn.AbstractClientConnAdapter.receiveR
>> esponseHeader(AbstractClientConnAdapter.java:223)
>>          at
>> org.apache.http.protocol.HttpRequestExecutor.doReceiveRespon
>> se(HttpRequestExecutor.java:272)
>>          at
>> org.apache.http.protocol.HttpRequestExecutor.execute(HttpReq
>> uestExecutor.java:124)
>>          at
>> org.apache.http.impl.client.DefaultRequestDirector.tryExecut
>> e(DefaultRequestDirector.java:685)
>>          at
>> org.apache.http.impl.client.DefaultRequestDirector.execute(D
>> efaultRequestDirector.java:487)
>>          at
>> org.apache.http.impl.client.AbstractHttpClient.doExecute(Abs
>> tractHttpClient.java:882)
>>          at
>> org.apache.http.impl.client.CloseableHttpClient.execute(Clos
>> eableHttpClient.java:82)
>>          at
>> org.apache.http.impl.client.CloseableHttpClient.execute(Clos
>> eableHttpClient.java:107)
>>          at
>> org.apache.http.impl.client.CloseableHttpClient.execute(Clos
>> eableHttpClient.java:55)
>>          at
>> org.keycloak.adapters.ServerRequest.invokeAccessCodeToToken(
>> ServerRequest.java:107)
>>          at
>> org.keycloak.adapters.OAuthRequestAuthenticator.resolveCode(
>> OAuthRequestAuthenticator.java:327)
>>          at
>> org.keycloak.adapters.OAuthRequestAuthenticator.authenticate
>> (OAuthRequestAuthenticator.java:273)
>>          at
>> org.keycloak.adapters.RequestAuthenticator.authenticate(Requ
>> estAuthenticator.java:130)
>>          at
>> org.keycloak.adapters.undertow.AbstractUndertowKeycloakAuthM
>> ech.keycloakAuthenticate(AbstractUndertowKeycloakAuthMech.java:110)
>>          at
>> org.keycloak.adapters.undertow.ServletKeycloakAuthMech.authe
>> nticate(ServletKeycloakAuthMech.java:92)
>>          at
>> io.undertow.security.impl.SecurityContextImpl$AuthAttempter.
>> transition(SecurityContextImpl.java:233)
>>          at
>> io.undertow.security.impl.SecurityContextImpl$AuthAttempter.
>> transition(SecurityContextImpl.java:250)
>>          at
>> io.undertow.security.impl.SecurityContextImpl$AuthAttempter.
>> access$100(SecurityContextImpl.java:219)
>>          at
>> io.undertow.security.impl.SecurityContextImpl.attemptAuthent
>> ication(SecurityContextImpl.java:121)
>>          at
>> io.undertow.security.impl.SecurityContextImpl.authTransition
>> (SecurityContextImpl.java:96)
>>          at
>> io.undertow.security.impl.SecurityContextImpl.authenticate(S
>> ecurityContextImpl.java:89)
>>          at
>> io.undertow.servlet.handlers.security.ServletAuthenticationC
>> allHandler.handleRequest(ServletAuthenticationCallHandler.java:55)
>>          at
>> io.undertow.server.handlers.DisableCacheHandler.handleReques
>> t(DisableCacheHandler.java:33)
>>          at
>> io.undertow.server.handlers.PredicateHandler.handleRequest(P
>> redicateHandler.java:43)
>>          at
>> io.undertow.security.handlers.AuthenticationConstraintHandle
>> r.handleRequest(AuthenticationConstraintHandler.java:51)
>>          at
>> io.undertow.security.handlers.AbstractConfidentialityHandler
>> .handleRequest(AbstractConfidentialityHandler.java:46)
>>          at
>> io.undertow.servlet.handlers.security.ServletConfidentiality
>> ConstraintHandler.handleRequest(ServletConfident
>> ialityConstraintHandler.java:64)
>>          at
>> io.undertow.servlet.handlers.security.ServletSecurityConstra
>> intHandler.handleRequest(ServletSecurityConstraintHandler.java:56)
>>          at
>> io.undertow.security.handlers.AuthenticationMechanismsHandle
>> r.handleRequest(AuthenticationMechanismsHandler.java:60)
>>          at
>> io.undertow.servlet.handlers.security.CachedAuthenticatedSes
>> sionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
>>          at
>> io.undertow.security.handlers.NotificationReceiverHandler.ha
>> ndleRequest(NotificationReceiverHandler.java:50)
>>          at
>> io.undertow.security.handlers.AbstractSecurityContextAssocia
>> tionHandler.handleRequest(AbstractSecurityContextAssociation
>> Handler.java:43)
>>          at
>> io.undertow.server.handlers.PredicateHandler.handleRequest(P
>> redicateHandler.java:43)
>>          at
>> org.wildfly.extension.undertow.security.jacc.JACCContextIdHa
>> ndler.handleRequest(JACCContextIdHandler.java:61)
>>          at
>> io.undertow.server.handlers.PredicateHandler.handleRequest(P
>> redicateHandler.java:43)
>>          at
>> org.keycloak.adapters.undertow.ServletPreAuthActionsHandler.
>> handleRequest(ServletPreAuthActionsHandler.java:69)
>>          at
>> io.undertow.server.handlers.PredicateHandler.handleRequest(P
>> redicateHandler.java:43)
>>          at
>> io.undertow.servlet.handlers.ServletInitialHandler.handleFir
>> stRequest(ServletInitialHandler.java:284)
>>          at
>> io.undertow.servlet.handlers.ServletInitialHandler.dispatchR
>> equest(ServletInitialHandler.java:263)
>>          at
>> io.undertow.servlet.handlers.ServletInitialHandler.access$00
>> 0(ServletInitialHandler.java:81)
>>          at
>> io.undertow.servlet.handlers.ServletInitialHandler$1.handleR
>> equest(ServletInitialHandler.java:174)
>>          at
>> io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
>>          at
>> io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:793)
>>          at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>> Executor.java:1142)
>> [rt.jar:1.8.0_111]
>>          at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>> lExecutor.java:617)
>> [rt.jar:1.8.0_111]
>>          at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_111]
>>
>> 2016-11-24 22:37:14,255 WARN
>>   [com.indicee.service.authorization.EjbTimerInterceptor] (default
>> task-13)
>> [  ] UserIdentityServiceImpl:findByEmail took 484 ms
>> 2016-11-24 22:37:14,256 WARN
>>   [com.indicee.service.authorization.EjbTimerInterceptor] (default
>> task-13)
>> [  ] AccountSrvImpl:isCurrentAccountUnknown took 499 ms
>> 2016-11-24 22:37:14,257 WARN
>>   [com.indicee.service.authorization.EjbTimerInterceptor] (default
>> task-13)
>> [  ] BrandedVariableLookupSrvImpl:cacheKey took 500 ms
>> 2016-11-24 22:37:14,959 WARN
>>   [com.indicee.service.authorization.EjbTimerInterceptor] (default
>> task-13)
>> [  ] UserIdentityServiceImpl:findByEmail took 697 ms
>> 2016-11-24 22:37:14,960 WARN
>>   [com.indicee.service.authorization.EjbTimerInterceptor] (default
>> task-13)
>> [  ] AccountSrvImpl:isCurrentAccountUnknown took 701 ms
>> 2016-11-24 22:37:14,962 WARN
>>   [com.indicee.service.authorization.EjbTimerInterceptor] (default
>> task-13)
>> [  ] BrandedVariableLookupSrvImpl:getVariables took 703 ms
>> 2016-11-24 22:37:15,095 INFO
>>   [com.indicee.service.servlet.filter.ClientRequestIdFilter] (default
>> task-14) [  ] Setting clientId [gwt_43cpg2jpm5oklfjkuue204jsmh] for
>> session
>> [qAYdgQ6PytsZ8kG5ah6mxEdmGeNPQpgT_2ExqU6A] created [1480026525644]
>> 2016-11-24 22:37:15,096 INFO
>>   [com.indicee.service.servlet.filter.ClientRequestIdFilter] (default
>> task-14) [  ] clientRequestId via atomic integer =
>> [gwt_43cpg2jpm5oklfjkuue204jsmh_0]
>> 2016-11-24 22:37:15,138 INFO
>>   [com.indicee.service.servlet.filter.ClientRequestIdFilter] (default
>> task-15) [  ] clientRequestId via atomic integer =
>> [gwt_43cpg2jpm5oklfjkuue204jsmh_1]
>> 2016-11-24 22:37:15,224 INFO
>>   [com.indicee.service.servlet.filter.ClientRequestIdFilter] (default
>> task-12) [  ] clientRequestId via atomic integer =
>> [gwt_43cpg2jpm5oklfjkuue204jsmh_2]
>> 2016-11-24 22:37:15,635 WARN
>>   [com.indicee.service.authorization.EjbTimerInterceptor]
>> (dInitialHandler.java:284)
>>          at
>> io.undertow.servlet.handlers.ServletInitialHandler.dispatchR
>> equest(ServletIni
>> tialHandler.java:263)
>>          at
>> io.undertow.servlet.handlers.ServletInitialHandler.access$00
>> 0(ServletInitialH
>> andler.java:81)
>>          at
>> io.undertow.servlet.handlers.ServletInitialHandler$1.handleR
>> equest(ServletIni
>> tialHandler.java:174)
>>          at
>> io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
>>          at
>> io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:793)
>>          at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>> Executor.java:114
>> 2) [rt.jar:1.8.0_111]
>>          at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>> lExecutor.java:61
>> 7) [rt.jar:1.8.0_111]
>>          at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_111]
>> _______________________________________________
>> keycloak-user mailing list
>> keycloak-user at lists.jboss.org
>> https://lists.jboss.org/mailman/listinfo/keycloak-user
>>
>
>
>