Hello, looking for any help on avoiding this in the future.
I’ve recently upgraded to keycloak 10.0.2 and had a case of JBOSS/wildly transaction timeout causing the server to become unresponsive (it gives 504 Gateway Timeout for any request from my application). I’m using postgres for keycloak’s data.
This was a recently provisioned keycloak instance. The initial startup looked fine in the logs, and there was light use for 7 days until I attempted to login to my application and started seeing these stacktraces appearing in the logs. Restarting the server cleared things up, but I want to avoid this happening again.
I don’t see any memory or CPU issues on keycloak’s host. There is a 5 minute default timeout in JBOSS and I’m wondering if increasing that would help at all, but wonder if there is a root cause somewhere that needs to be addressed.
Here is my keycloak.json:
{
“realm”: “Tasktop”,
“auth-server-url”: “/auth”,
“ssl-required”: “all”,
“resource”: “tasktop”,
“disable-trust-manager”: true,
“enable-basic-auth”: true,
“credentials”: {
“secret”: “${env.KEYCLOAK_SECRET}”
},
“principal-attribute”: “preferred_username”
}
The stack trace says that threads were being killed while attempting backchannel logout. This caused the entire keycloak server to stop responding.
e[0me[33m12:16:58,234 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffffac110003:-6feccc04:5f7e5061:84da6 aborting with 1 threads active!
e[0me[33m12:16:58,235 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffffac110003:-6feccc04:5f7e5061:84da6
e[0me[33m12:16:58,238 WARN [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffac110003:-6feccc04:5f7e5061:84da9 in state RUN
e[0me[33m12:16:58,239 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffffac110003:-6feccc04:5f7e5061:84da9 invoked while multiple threads active within it.
e[0me[33m12:16:58,245 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012381: Action id 0:ffffac110003:-6feccc04:5f7e5061:84da9 completed with multiple threads - thread default task-25 was in progress with java.net.SocketInputStream.socketRead0(Native Method)
java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
java.net.SocketInputStream.read(SocketInputStream.java:171)
java.net.SocketInputStream.read(SocketInputStream.java:141)
sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
sun.security.ssl.InputRecord.read(InputRecord.java:503)
sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:975)
sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:933)
sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:157)
org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
org.keycloak.connections.httpclient.DefaultHttpClientFactory$1.postText(DefaultHttpClientFactory.java:86)
org.keycloak.services.managers.ResourceAdminManager.sendLogoutRequest(ResourceAdminManager.java:249)
org.keycloak.services.managers.ResourceAdminManager.logoutClientSessions(ResourceAdminManager.java:188)
org.keycloak.services.managers.ResourceAdminManager.logoutClientSession(ResourceAdminManager.java:143)
org.keycloak.protocol.oidc.OIDCLoginProtocol.backchannelLogout(OIDCLoginProtocol.java:316)
org.keycloak.services.managers.AuthenticationManager.backchannelLogoutClientSession(AuthenticationManager.java:407)
org.keycloak.services.managers.AuthenticationManager.lambda$backchannelLogoutAll$1(AuthenticationManager.java:314)
org.keycloak.services.managers.AuthenticationManager$$Lambda$1064/940120192.accept(Unknown Source)
java.util.HashMap$Values.forEach(HashMap.java:981)
java.util.Collections$UnmodifiableCollection.forEach(Collections.java:1082)
org.keycloak.services.managers.AuthenticationManager.backchannelLogoutAll(AuthenticationManager.java:313)
org.keycloak.services.managers.AuthenticationManager.backchannelLogout(AuthenticationManager.java:247)
org.keycloak.services.managers.AuthenticationManager.backchannelLogout(AuthenticationManager.java:215)
org.keycloak.services.managers.AuthenticationManager.verifyIdentityToken(AuthenticationManager.java:1267)
org.keycloak.services.managers.AuthenticationManager.authenticateIdentityCookie(AuthenticationManager.java:737)
org.keycloak.authentication.authenticators.browser.CookieAuthenticator.authenticate(CookieAuthenticator.java:42)
org.keycloak.authentication.DefaultAuthenticationFlow.processSingleFlowExecutionModel(DefaultAuthenticationFlow.java:438)
org.keycloak.authentication.DefaultAuthenticationFlow.processFlow(DefaultAuthenticationFlow.java:270)
org.keycloak.authentication.AuthenticationProcessor.authenticateOnly(AuthenticationProcessor.java:976)
org.keycloak.authentication.AuthenticationProcessor.authenticate(AuthenticationProcessor.java:838)
org.keycloak.protocol.AuthorizationEndpointBase.handleBrowserAuthenticationRequest(AuthorizationEndpointBase.java:151)
org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.buildAuthorizationCodeAuthorizationResponse(AuthorizationEndpoint.java:471)
org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.process(AuthorizationEndpoint.java:167)
org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.buildGet(AuthorizationEndpoint.java:112)
sun.reflect.GeneratedMethodAccessor436.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:498)
org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:138)
org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:535)
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:424)
org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:385)
org.jboss.resteasy.core.ResourceMethodInvoker$$Lambda$919/14317600.get(Unknown Source)
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:356)
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:387)
org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:356)
org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:150)
org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:110)
org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:141)
org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:104)
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:440)
org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229)
org.jboss.resteasy.core.SynchronousDispatcher$$Lambda$917/414793959.run(Unknown Source)
org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135)
org.jboss.resteasy.core.SynchronousDispatcher$$Lambda$918/1019645209.get(Unknown Source)
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:356)
org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138)
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215)
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
org.keycloak.services.filters.KeycloakSessionServletFilter.doFilter(KeycloakSessionServletFilter.java:91)
io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:269)
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78)
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133)
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130)
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction$$Lambda$694/853304286.call(Unknown Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1541)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$695/1133335298.call(Unknown Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1541)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$695/1133335298.call(Unknown Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1541)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$695/1133335298.call(Unknown Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1541)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$695/1133335298.call(Unknown Source)
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249)
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78)
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99)
io.undertow.server.Connectors.executeRootHandler(Connectors.java:370)
io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1348)
java.lang.Thread.run(Thread.java:748)