Details
-
Bug
-
Resolution: Done
-
Major
-
RH-SSO-7.2.2.GA
-
None
-
Keycloak Sprint 9, Keycloak Sprint 10
Description
Right now, Keycloak requires to preload offline sessions from DB at startup.
In case that Keycloak fails to do it within 5 minutes (usually happens if there is some (or more) aspects like: a) many offline sessions, b) slower connection to DB, c) Custom UserStorage provider with slower connection to DB) there is an exception in server.log and server fails to start:
2018-06-30 00:22:29,457 DEBUG [org.keycloak.models.sessions.infinispan.initializer.InfinispanCacheInitializer] (ServerService Thread Pool -- 64) New initializer state pushed. The state is: sessionsCount: 16 2869, finished segments count: 1629, non-finished segments count: 1629 2018-06-30 00:22:29,467 DEBUG [org.keycloak.models.sessions.infinispan.initializer.OfflinePersistentUserSessionLoader] (ServerService Thread Pool -- 64) Persistent sessions loaded successfully! 2018-06-30 00:22:29,477 DEBUG [org.keycloak.models.sessions.infinispan.initializer.OfflinePersistentUserSessionLoader] (ServerService Thread Pool -- 64) Persistent sessions loaded already. 2018-06-30 00:22:29,478 WARN [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) ARJUNA012077: Abort called on already aborted atomic action 0:ffffac199023:-56a74a79:5b363ba2:2e 2018-06-30 00:22:29,482 WARN [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) ARJUNA012077: Abort called on already aborted atomic action 0:ffffac199023:-56a74a79:5b363ba2:26 2018-06-30 00:22:29,582 INFO [org.jboss.as.server] (Thread-2) WFLYSRV0220: Server shutdown has been requested via an OS signal 2018-06-30 00:22:29,587 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 64) MSC000001: Failed to start service jboss.undertow.deployment.default-server.default-host./auth: org.jboss.msc.ser vice.StartException in service jboss.undertow.deployment.default-server.default-host./auth: java.lang.RuntimeException: RESTEASY003325: Failed to construct public org.keycloak.services.resources.KeycloakApp lication(javax.servlet.ServletContext,org.jboss.resteasy.core.Dispatcher) at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:84) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) at org.jboss.threads.JBossThread.run(JBossThread.java:320) Caused by: java.lang.RuntimeException: RESTEASY003325: Failed to construct public org.keycloak.services.resources.KeycloakApplication(javax.servlet.ServletContext,org.jboss.resteasy.core.Dispatcher) at org.jboss.resteasy.core.ConstructorInjectorImpl.construct(ConstructorInjectorImpl.java:162) at org.jboss.resteasy.spi.ResteasyProviderFactory.createProviderInstance(ResteasyProviderFactory.java:2298) at org.jboss.resteasy.spi.ResteasyDeployment.createApplication(ResteasyDeployment.java:340) at org.jboss.resteasy.spi.ResteasyDeployment.start(ResteasyDeployment.java:253) at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.init(ServletContainerDispatcher.java:120) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.init(HttpServletDispatcher.java:36) at io.undertow.servlet.core.LifecyleInterceptorInvocation.proceed(LifecyleInterceptorInvocation.java:117) at org.wildfly.extension.undertow.security.RunAsLifecycleInterceptor.init(RunAsLifecycleInterceptor.java:78) at io.undertow.servlet.core.LifecyleInterceptorInvocation.proceed(LifecyleInterceptorInvocation.java:103) at io.undertow.servlet.core.ManagedServlet$DefaultInstanceStrategy.start(ManagedServlet.java:250) at io.undertow.servlet.core.ManagedServlet.createServlet(ManagedServlet.java:133) at io.undertow.servlet.core.DeploymentManagerImpl$2.call(DeploymentManagerImpl.java:565) at io.undertow.servlet.core.DeploymentManagerImpl$2.call(DeploymentManagerImpl.java:536) at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42) at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at io.undertow.servlet.core.DeploymentManagerImpl.start(DeploymentManagerImpl.java:578) at org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:100) at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81) ... 6 more Caused by: java.lang.RuntimeException: javax.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffffac199023:-56a74a79:5b363ba2:2e at org.keycloak.transaction.JtaTransactionWrapper.handleException(JtaTransactionWrapper.java:77) at org.keycloak.transaction.JtaTransactionWrapper.commit(JtaTransactionWrapper.java:94) at org.keycloak.services.DefaultKeycloakTransactionManager.commit(DefaultKeycloakTransactionManager.java:136) at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:233) at org.keycloak.models.sessions.infinispan.InfinispanUserSessionProviderFactory.loadPersistentSessions(InfinispanUserSessionProviderFactory.java:145) at org.keycloak.models.sessions.infinispan.InfinispanUserSessionProviderFactory$1.onEvent(InfinispanUserSessionProviderFactory.java:116) at org.keycloak.services.DefaultKeycloakSessionFactory.publish(DefaultKeycloakSessionFactory.java:68) at org.keycloak.services.resources.KeycloakApplication$2.run(KeycloakApplication.java:167) at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:227) at org.keycloak.services.resources.KeycloakApplication.<init>(KeycloakApplication.java:160) at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.jboss.resteasy.core.ConstructorInjectorImpl.construct(ConstructorInjectorImpl.java:150) ... 28 more Caused by: javax.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffffac199023:-56a74a79:5b363ba2:2e at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1279) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89) at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73) at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71) at org.keycloak.transaction.JtaTransactionWrapper.commit(JtaTransactionWrapper.java:92) ... 41 more 2018-06-30 00:22:29,680 WARN [org.infinispan.CLUSTER] (remote-thread--p11-t3) [Context=sessions]ISPN000312: Lost data because of graceful leaver iskssowebprd04 2018-06-30 00:22:29,715 WARN [org.infinispan.CLUSTER] (remote-thread--p11-t9) [Context=loginFailures]ISPN000312: Lost data because of graceful leaver iskssowebprd04 2018-06-30 00:22:29,730 WARN [org.infinispan.CLUSTER] (remote-thread--p11-t14) [Context=offlineClientSessions]ISPN000312: Lost data because of graceful leaver iskssowebprd04 2018-06-30 00:22:29,744 WARN [org.infinispan.CLUSTER] (remote-thread--p11-t13) [Context=clientSessions]ISPN000312: Lost data because of graceful leaver iskssowebprd04 2018-06-30 00:22:29,757 WARN [org.infinispan.CLUSTER] (remote-thread--p11-t10) [Context=authenticationSessions]ISPN000312: Lost data because of graceful leaver iskssowebprd04 2018-06-30 00:22:29,761 WARN [org.infinispan.CLUSTER] (remote-thread--p11-t11) [Context=offlineSessions]ISPN000312: Lost data because of graceful leaver iskssowebprd04 2018-06-30 00:22:29,809 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 67) WFLYUT0022: Unregistered web context: '/jolokia' from server 'default-server' 2018-06-30 00:22:29,824 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-4) ISPN000080: Disconnecting JGroups channel ejb
The issue is, that always when Keycloak transaction is started, we also automatically enlist and start JTA transaction (See DefaultKeycloakTransactionManager.begin() ).
One possibility is to have the option to skip JTA entirely.
Another possibility is to start JTA transaction "lazily" just if there is another KeycloakTransaction enlisted. Issue is that custom UserStorage by customer may use JPA directly (not use Keycloak TransactionManager API), which may result that JPA code by customer won't use JTA transaction.
NOTE: DefaultKeycloakTransactionManager has setJtaPolicy/getJtaPolicy methods, but it is currently not supported by the configuration.
