Re: [keycloak-dev] Exception in 1.7.0 during login using federation provider

On Jan 11, 2016, at 12:39 PM, Scott Rossillo <srossillo(a)smartling.com&gt; wrote: Hey, I’m trying to publish an example of how to do on demand user migration using a federation provider. It’s a modified version of what we use on an older Keycloak version. The error I’m getting (with H2, Keycloak 1.7.0 out-of-the-box) is below. At the time the exception is thrown, Kecyloak hasn’t attempted to validate credentials yet. It has only called these methods: - UserModel getUserByUsername(RealmModel realm, String username); - public boolean isValid(RealmModel realm, UserModel local); After calling session.users().addUser() am I supposed to release something? Thanks, Scott ------- Methods: @Override public UserModel getUserByUsername(RealmModel realm, String username) { { String username = rawUsername.toLowerCase().trim(); FederatedUserModel remoteUser = federatedUserService.getUserDetails(username); LOG.infof("Creating user model for: %s", username); UserModel userModel = session.users().addUser(realm, username); if (!username.equals(remoteUser.getEmail())) { throw new IllegalStateException(String.format("Local and remote users differ: [%s != %s]", username, remoteUser.getUsername())); } userModel.setFederationLink(model.getId()); userModel.setEnabled(remoteUser.isEnabled()); userModel.setEmail(username); userModel.setEmailVerified(remoteUser.isEmailVerified()); userModel.setFirstName(remoteUser.getFirstName()); userModel.setLastName(remoteUser.getLastName()); if (remoteUser.getAttributes() != null) { Map<String, List<String>> attributes = remoteUser.getAttributes(); for (String attributeName : attributes.keySet()) userModel.setAttribute(attributeName, attributes.get(attributeName)); } if (remoteUser.getRoles() != null) { for (String role : remoteUser.getRoles()) { RoleModel roleModel = realm.getRole(role); if (roleModel != null) { userModel.grantRole(roleModel); LOG.infof("Granted user %s, role %s", username, role); } } } return userModel; } @Override public boolean isValid(RealmModel realm, UserModel local) { Response response = federatedUserService.validateUserExists(local.getUsername()); return HttpStatus.SC_ACCEPTED == response.getStatus(); } Exception: 2:13:51,497 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-88) SQL Error: 50200, SQLState: HYT00 12:13:51,498 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-88) Timeout trying to lock table "USER_ENTITY"; SQL statement: select userentity0_.ID as ID1_46_, userentity0_.CREATED_TIMESTAMP as CREATED_2_46_, userentity0_.EMAIL as EMAIL3_46_, userentity0_.EMAIL_CONSTRAINT as EMAIL_CO4_46_, userentity0_.EMAIL_VERIFIED as EMAIL_VE5_46_, userentity0_.ENABLED as ENABLED6_46_, userentity0_.FEDERATION_LINK as FEDERATI7_46_, userentity0_.FIRST_NAME as FIRST_NA8_46_, userentity0_.LAST_NAME as LAST_NAM9_46_, userentity0_.REALM_ID as REALM_I10_46_, userentity0_.SERVICE_ACCOUNT_CLIENT_LINK as SERVICE11_46_, userentity0_.TOTP as TOTP12_46_, userentity0_.USERNAME as USERNAM13_46_ from USER_ENTITY userentity0_ where userentity0_.ID=? and userentity0_.REALM_ID=? [50200-173] 12:13:51,499 ERROR [org.keycloak.authentication.AuthenticationProcessor] (default task-88) failed authentication: javax.persistence.PessimisticLockException: could not extract ResultSet at org.hibernate.jpa.spi.AbstractEntityManagerImpl.wrapLockException(AbstractEntityManagerImpl.java:1831) at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1720) at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1677) at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:458) at org.keycloak.models.jpa.JpaUserProvider.getUserById(JpaUserProvider.java:260) at org.keycloak.models.cache.infinispan.DefaultCacheUserProvider.getUserById(DefaultCacheUserProvider.java:122) at org.keycloak.models.UserFederationManager.deleteInvalidUser(UserFederationManager.java:112) at org.keycloak.models.UserFederationManager.validateUser(UserFederationManager.java:100) at org.keycloak.models.UserFederationManager.validCredentials(UserFederationManager.java:409) at org.keycloak.authentication.authenticators.browser.AbstractUsernameFormAuthenticator.validatePassword(AbstractUsernameFormAuthenticator.java:152) at org.keycloak.authentication.authenticators.browser.AbstractUsernameFormAuthenticator.validateUserAndPassword(AbstractUsernameFormAuthenticator.java:128) at org.keycloak.authentication.authenticators.browser.UsernamePasswordForm.validateForm(UsernamePasswordForm.java:41) at org.keycloak.authentication.authenticators.browser.UsernamePasswordForm.action(UsernamePasswordForm.java:34) at org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:65) at org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:57) at org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:744) at org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:299) at org.keycloak.services.resources.LoginActionsService.processAuthentication(LoginActionsService.java:280) at org.keycloak.services.resources.LoginActionsService.authenticateForm(LoginActionsService.java:326) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137) at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:296) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:250) at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:140) at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:103) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179) at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:86) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:130) at org.keycloak.services.filters.KeycloakSessionServletFilter.doFilter(KeycloakSessionServletFilter.java:61) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132) at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:85) at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62) at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131) at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46) at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64) at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58) at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:72) at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50) at io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:282) at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:261) at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:80) at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:172) at io.undertow.server.Connectors.executeRootHandler(Connectors.java:199) at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:774) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) Caused by: org.hibernate.PessimisticLockException: could not extract ResultSet at org.hibernate.dialect.H2Dialect$2.convert(H2Dialect.java:342) at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:126) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:112) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:91) at org.hibernate.loader.Loader.getResultSet(Loader.java:2066) at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1863) at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1839) at org.hibernate.loader.Loader.doQuery(Loader.java:910) at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:355) at org.hibernate.loader.Loader.doList(Loader.java:2554) at org.hibernate.loader.Loader.doList(Loader.java:2540) at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2370) at org.hibernate.loader.Loader.list(Loader.java:2365) at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:497) at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:387) at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:236) at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1300) at org.hibernate.internal.QueryImpl.list(QueryImpl.java:103) at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:573) at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:449) ... 62 more Caused by: org.h2.jdbc.JdbcSQLException: Timeout trying to lock table "USER_ENTITY"; SQL statement: select userentity0_.ID as ID1_46_, userentity0_.CREATED_TIMESTAMP as CREATED_2_46_, userentity0_.EMAIL as EMAIL3_46_, userentity0_.EMAIL_CONSTRAINT as EMAIL_CO4_46_, userentity0_.EMAIL_VERIFIED as EMAIL_VE5_46_, userentity0_.ENABLED as ENABLED6_46_, userentity0_.FEDERATION_LINK as FEDERATI7_46_, userentity0_.FIRST_NAME as FIRST_NA8_46_, userentity0_.LAST_NAME as LAST_NAM9_46_, userentity0_.REALM_ID as REALM_I10_46_, userentity0_.SERVICE_ACCOUNT_CLIENT_LINK as SERVICE11_46_, userentity0_.TOTP as TOTP12_46_, userentity0_.USERNAME as USERNAM13_46_ from USER_ENTITY userentity0_ where userentity0_.ID=? and userentity0_.REALM_ID=? [50200-173] at org.h2.message.DbException.getJdbcSQLException(DbException.java:331) at org.h2.message.DbException.get(DbException.java:171) at org.h2.message.DbException.get(DbException.java:148) at org.h2.table.RegularTable.doLock(RegularTable.java:521) at org.h2.table.RegularTable.lock(RegularTable.java:455) at org.h2.table.TableFilter.lock(TableFilter.java:145) at org.h2.command.dml.Select.queryWithoutCache(Select.java:611) at org.h2.command.dml.Query.query(Query.java:314) at org.h2.command.dml.Query.query(Query.java:284) at org.h2.command.dml.Query.query(Query.java:36) at org.h2.command.CommandContainer.query(CommandContainer.java:91) at org.h2.command.Command.executeQuery(Command.java:195) at org.h2.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:106) at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:504) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:82) ... 78 more