[keycloak-dev] Outage Issue

Thursday, 21 June 2018

Hiya

I was wondering if anyone has come across this before. We have Keycloak
running in a kubernetes cluster, a mysql RDS, and standalone-ha setup using
two gossip servers, each running behind a kube service and passed in via
environment variables

<protocol type="TCPGOSSIP">
  <property
name="initial_hosts">${env.GOSSIP_ROUTER_HOST}</property>
</protocol>

Cluster appears to work fine, a new node added makes a change to topology
and so forth. We do however out of the blue get the following error on
occasion, every couple of weeks... Shortly after the rest of the replicas
become affected, the health check on the /auth fails and or login attempts
begin to timeout .. At present the only solution is to completely cycle the
cluster.

13:07:52,451 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)
ARJUNA012108: CheckedAction::check - atomic action
0:ffff0a0a8b0a:-6d4f7aec:5b0ef057:47876e aborting with 1 threads active!
13:07:52,451 WARN
[org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorTrackingImpl]
(Transaction Reaper Worker 0) HHH000451: Transaction afterCompletion called
by a background thread; delaying afterCompletion processing until the
original thread can handle it. [status=4]
13:07:52,451 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)
ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction
Reaper Worker 0,5,main] successfully canceled TX
0:ffff0a0a8b0a:-6d4f7aec:5b0ef057:47876e
13:07:55,475 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper)
ARJUNA012117: TransactionReaper::check timeout for TX
0:ffff0a0a8b0a:-6d4f7aec:5b0ef057:4787b9 in state  RUN
13:07:55,476 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)
ARJUNA012095: Abort of action id 0:ffff0a0a8b0a:-6d4f7aec:5b0ef057:4787b9
invoked while multiple threads active within it.
13:07:55,480 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)
ARJUNA012381: Action id 0:ffff0a0a8b0a:-6d4f7aec:5b0ef057:4787b9 completed
with multiple threads - thread default task-64 was in progress with
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
org.apache.http.pool.PoolEntryFuture.await(PoolEntryFuture.java:138)
org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:306)
org.apache.http.pool.AbstractConnPool.access$000(AbstractConnPool.java:64)
org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:192)
org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:185)
org.apache.http.pool.PoolEntryFuture.get(PoolEntryFuture.java:107)
org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:276)
org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:263)
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
org.keycloak.broker.provider.util.SimpleHttp.makeRequest(SimpleHttp.java:185)
org.keycloak.broker.provider.util.SimpleHttp.asResponse(SimpleHttp.java:154)
org.keycloak.broker.provider.util.SimpleHttp.asString(SimpleHttp.java:146)
org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider$Endpoint.authResponse(AbstractOAuth2IdentityProvider.java:397)
sun.reflect.GeneratedMethodAccessor994.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:140)
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295)
org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249)
org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:138)
org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:107)
org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:133)
org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:101)
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:406)
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:213)
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:228)
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:790)
io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
org.keycloak.services.filters.KeycloakSessionServletFilter.doFilter(KeycloakSessionServletFilter.java:90)
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.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.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
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:292)
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
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$1243/578097420.call(Unknown
Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1244/197032188.call(Unknown
Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1244/197032188.call(Unknown
Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1244/197032188.call(Unknown
Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1244/197032188.call(Unknown
Source)
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
io.undertow.server.Connectors.executeRootHandler(Connectors.java:326)
io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)

Repeating over and over ... Just before is

11:26:08,882 WARN  [org.keycloak.events] (default task-166)
type=CODE_TO_TOKEN_ERROR, realmId=XXX, clientId=XXXX, userId=null,
ipAddress=XXXXXXXXXX , error=invalid_code, grant_type=authorization_code,
code_id=XXXXXXXX , client_auth_method=client-secret
11:30:04,172 WARN  [org.keycloak.services.managers.AuthenticationManager]
(default task-100) Some clients have been not been logged out for user
XXXXXXXXXXXXXXXXXXX   in hod-ci realm: XXXXX
11:30:04,203 WARN  [org.keycloak.events] (default task-92)
type=IDENTITY_PROVIDER_LOGIN_ERROR, realmId=HOD-CI, clientId=null,
userId=null, ipAddress=213.251.23.186, error=expired_code,
identity_provider=O365, restart_after_timeout=true
11:38:13,851 WARN  [org.keycloak.forms.login.freemarker.model.ProfileBean]
(default task-88) There are more values for attribute 'group' of user
'XXXX\XXXXXX' . Will display just first value
11:43:37,370 WARN  [org.keycloak.events] (default task-36)
type=LOGIN_ERROR, realmId=lev, clientId=lev-web, userId=null,
ipAddress=XXXXXXXX, error=user_not_found, auth_method=openid-connect,
auth_type=code, redirect_uri=https://lev.homeoffice.gov.uk/oauth/callback,
code_id=5a08f532-1051-4805-8dd6-d71362303521, username=XXXXXXXXX
11:47:01,018 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper)
ARJUNA012117: TransactionReaper::check timeout for TX
0:ffff0a0a8b0a:-6d4f7aec:5b0ef057:46efe0 in state  RUN
11:47:01,019 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)
ARJUNA012095: Abort of action id 0:ffff0a0a8b0a:-6d4f7aec:5b0ef057:46efe0
invoked while multiple threads active within it.
11:47:01,022 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0)
ARJUNA012381: Action id 0:ffff0a0a8b0a:-6d4f7aec:5b0ef057:46efe0 completed
with multiple threads - thread default task-165 was in progress with
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
org.apache.http.pool.PoolEntryFuture.await(PoolEntryFuture.java:138)
org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:306)
org.apache.http.pool.AbstractConnPool.access$000(AbstractConnPool.java:64)
org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:192)
org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:185)
org.apache.http.pool.PoolEntryFuture.get(PoolEntryFuture.java:107)
org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:276)
org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:263)
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
org.keycloak.broker.provider.util.SimpleHttp.makeRequest(SimpleHttp.java:185)
org.keycloak.broker.provider.util.SimpleHttp.asResponse(SimpleHttp.java:154)
org.keycloak.broker.provider.util.SimpleHttp.asString(SimpleHttp.java:146)
org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider$Endpoint.authResponse(AbstractOAuth2IdentityProvider.java:397)
sun.reflect.GeneratedMethodAccessor994.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:140)
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295)
org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249)
org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:138)
org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:107)
org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:133)
org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:101)
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:406)
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:213)
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:228)
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:790)
io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
org.keycloak.services.filters.KeycloakSessionServletFilter.doFilter(KeycloakSessionServletFilter.java:90)
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.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.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
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:292)
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
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$1243/578097420.call(Unknown
Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1244/197032188.call(Unknown
Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1244/197032188.call(Unknown
Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1244/197032188.call(Unknown
Source)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1244/197032188.call(Unknown
Source)
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
io.undertow.server.Connectors.executeRootHandler(Connectors.java:326)
io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)

Rohith

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

[keycloak-dev] Outage Issue