-
Type:
Bug
-
Status: Resolved (View Workflow)
-
Priority:
Major
-
Resolution: Duplicate Issue
-
Affects Version/s: 3.0.0.Final
-
Fix Version/s: 3.4.0.Final
-
Component/s: Adapters, Testsuite - Performance
-
Labels:
-
Environment:
CentOS 7, Java SE 8 (JRE 1.8.0_131), Azure MSSQL
-
Security Sensitive Issue:This issue is security relevant
-
Steps to Reproduce:
-
Docs QE Status:NEW
-
QE Status:NEW
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.
The tests are being run from 40 VMs that hit the server simultaneously each executing separate login tests. Each server using it's own set of test accounts, so no two servers log in as the same user, but a server may log in multiple times as the same user through its testing cycle.
Keycloak is hosted in Azure, and the latest version of the following driver is used to connect with Azure MSSQL:
<driver name="sqlserver" module="com.microsoft">
<driver-class>com.microsoft.sqlserver.jdbc.SQLServerDriver</driver-class>
<xa-datasource-class>com.microsoft.sqlserver.jdbc.SQLServerXADataSource</xa-datasource-class>
</driver>
My guess is that two login processes are attempting to update a user's federated property at almost the same time and deadlock with eachother, or the lock from the first update isn't released until a little while after the user successfully logs in.
Despite the deadlock, the greater issue is that deadlocked threads do not seem to get recycled, even after the login process has failed from the client's perspective.
- blocks
-
KEYCLOAK-4966 Tracker: MSSQL deadlocks
-
- Open
-
- is duplicated by
-
KEYCLOAK-5230 Indexes on USER_ID missing from the federated user tables
-
- Closed
-
- is related to
-
KEYCLOAK-4966 Tracker: MSSQL deadlocks
-
- Open
-