[keycloak-dev] AbstractUserAdapterFederatedStorage.setSingleAttribute(, ) causing deadlocks

[Hynek Mlnarik]

Please file a JIRA. Keycloak w/ MSSQL has some known issues with
deadlocks and these need to be investigated. If you can share some
more details on reproducing the issues (configuration of the load
testing), that would be great. Please link it to
https://issues.jboss.org/browse/KEYCLOAK-4966.

On Wed, May 24, 2017 at 5:58 PM, David Lustig <DLustig at carbonite.com> wrote:
> Greetings,
>
> I have developed a federated user storage authenticator for Keycloak.  Upon each login we set/update at least one federated attribute on the user using AbstractUserAdapterFederatedStorage.setSingleAttribute(String name, String value).  During load testing, though, Keycloak starts running into deadlock issues that look to be caused by this method.  The error logged is:
>
> 2017-05-24 05:15:01,376 WARN  [org.keycloak.services] (default task-7) KC-SERVICES0013: Failed authentication: javax.persistence.PersistenceException: org.hibernate.exception.LockAcquisitionException: could not execute statement
>         at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1692)
>         at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602)
>         at org.hibernate.jpa.spi.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1700)
>         at org.hibernate.jpa.spi.AbstractQueryImpl.executeUpdate(AbstractQueryImpl.java:70)
>         at org.keycloak.storage.jpa.JpaUserFederatedStorageProvider.deleteAttribute(JpaUserFederatedStorageProvider.java:112)
>         at org.keycloak.storage.jpa.JpaUserFederatedStorageProvider.setSingleAttribute(JpaUserFederatedStorageProvider.java:129)
>        at org.keycloak.storage.adapter.AbstractUserAdapterFederatedStorage.setSingleAttribute(AbstractUserAdapterFederatedStorage.java:341)
>         ...
> Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement
>         at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:123)
>         at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
>         at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109)
>         at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:95)
>         at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:207)
>         at org.hibernate.hql.internal.ast.exec.BasicExecutor.doExecute(BasicExecutor.java:91)
>         at org.hibernate.hql.internal.ast.exec.BasicExecutor.execute(BasicExecutor.java:60)
>         at org.hibernate.hql.internal.ast.exec.DeleteExecutor.execute(DeleteExecutor.java:111)
>         at org.hibernate.hql.internal.ast.QueryTranslatorImpl.executeUpdate(QueryTranslatorImpl.java:429)
>         at org.hibernate.engine.query.spi.HQLQueryPlan.performExecuteUpdate(HQLQueryPlan.java:374)
>         at org.hibernate.internal.SessionImpl.executeUpdate(SessionImpl.java:1348)
>         at org.hibernate.internal.QueryImpl.executeUpdate(QueryImpl.java:102)
>         at org.hibernate.jpa.internal.QueryImpl.internalExecuteUpdate(QueryImpl.java:405)
>         at org.hibernate.jpa.spi.AbstractQueryImpl.executeUpdate(AbstractQueryImpl.java:61)
>         ... 65 more
> Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 111) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
>         at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:217)
>         at com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1655)
>         at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:440)
>         at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:385)
>         at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7505)
>         at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:2445)
>         at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:191)
>         at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:166)
>         at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.executeUpdate(SQLServerPreparedStatement.java:328)
>         at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:537)
>         at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204)
>         ... 74 more
>
> Eventually, none of the deadlocks are released and the JVM crashes due to an out-of-memory error.  Is deadlocking expected behavior?  Are there any programming practices that should be followed that would prevent setSingleAttribute(,) from deadlocking the system in all situations, including high usage?
>
> Thanks for your help,
>
> David Lustig
> This message is the property of CARBONITE, INC. and may contain confidential or privileged information.
> If this message has been delivered to you by mistake, then do not copy or deliver this message to anyone.  Instead, destroy it and notify me by reply e-mail
> _______________________________________________
> keycloak-dev mailing list
> keycloak-dev at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/keycloak-dev



-- 

--Hynek