I am having a very strange issue in my keycloak.
When I am accessing the keycloak via admin UI or via keycloak admin API everything is fine. But when I tried to call the token API in postman with wrong client id and client secret, the whole keycloak application stopped working.
{{base_path}}/realms/{{realm_name}}/protocol/openid-connect/token
Tried the same scenario in my local and development setup it works fine as expected. but, my UAT environment configured with kubarnetes and docker have the issue. The other environments giving proper response as,
{
"error": "invalid_client",
"error_description": "Invalid client or Invalid client credentials"
}
And the log in the keycloak shows that there is a DB connection issue. But when i checked all the configuration in my development server and UAT server everything is same. Do any one face the similar issue or know why it is happening suddenly after an API call?
2024-05-07 05:42:59,850 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (executor-thread-127) Sorry, acquisition timeout!
2024-05-07 05:42:59,859 ERROR [org.keycloak.services] (executor-thread-127) KC-SERVICES0015: Unexpected error when authenticating client: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection [Sorry, acquisition timeout!] [n/a]
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:63)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:94)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:116)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:143)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:54)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:153)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:183)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:155)
at org.hibernate.sql.exec.spi.JdbcSelectExecutor.lambda$list$0(JdbcSelectExecutor.java:85)
at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:231)
at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.getResultSet(DeferredResultSetAccess.java:167)
at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.advanceNext(JdbcValuesResultSetImpl.java:218)
at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.processNext(JdbcValuesResultSetImpl.java:98)
at org.hibernate.sql.results.jdbc.internal.AbstractJdbcValues.next(AbstractJdbcValues.java:19)
at org.hibernate.sql.results.internal.RowProcessingStateStandardImpl.next(RowProcessingStateStandardImpl.java:66)
at org.hibernate.sql.results.spi.ListResultsConsumer.consume(ListResultsConsumer.java:202)
at org.hibernate.sql.results.spi.ListResultsConsumer.consume(ListResultsConsumer.java:33)
at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.doExecuteQuery(JdbcSelectExecutorStandardImpl.java:209)
at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.executeQuery(JdbcSelectExecutorStandardImpl.java:83)
at org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:76)
at org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:65)
at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.lambda$new$2(ConcreteSqmSelectQueryPlan.java:137)
at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.withCacheableSqmInterpretation(ConcreteSqmSelectQueryPlan.java:362)
at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.performList(ConcreteSqmSelectQueryPlan.java:303)
at org.hibernate.query.sqm.internal.QuerySqmImpl.doList(QuerySqmImpl.java:509)
at org.hibernate.query.spi.AbstractSelectionQuery.list(AbstractSelectionQuery.java:427)
at org.hibernate.query.Query.getResultList(Query.java:120)
at org.keycloak.models.jpa.JpaRealmProvider.getClientByClientId(JpaRealmProvider.java:825)
at org.keycloak.storage.ClientStorageManager.getClientByClientId(ClientStorageManager.java:149)
at org.keycloak.models.cache.infinispan.RealmCacheSession.prepareCachedClientByClientId(RealmCacheSession.java:1291)
at org.keycloak.models.cache.infinispan.RealmCacheSession.lambda$getClientByClientId$6(RealmCacheSession.java:1282)
at org.keycloak.models.cache.infinispan.RealmCacheManager.computeSerialized(RealmCacheManager.java:142)
at org.keycloak.models.cache.infinispan.RealmCacheSession.getClientByClientId(RealmCacheSession.java:1282)
at org.keycloak.authentication.authenticators.client.ClientIdAndSecretAuthenticator.authenticateClient(ClientIdAndSecretAuthenticator.java:105)
at org.keycloak.authentication.ClientAuthenticationFlow.processFlow(ClientAuthenticationFlow.java:72)
at org.keycloak.authentication.AuthenticationProcessor.authenticateClient(AuthenticationProcessor.java:893)
at org.keycloak.protocol.oidc.utils.AuthorizeClientUtil.authorizeClient(AuthorizeClientUtil.java:50)
at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.checkClient(TokenEndpoint.java:168)
at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.processGrantRequest(TokenEndpoint.java:134)
at org.keycloak.protocol.oidc.endpoints.TokenEndpoint$quarkusrestinvoker$processGrantRequest_6408e15340992839b66447750c221d9aaa837bd7.invoke(Unknown Source)
at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)
at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1512)
at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: java.sql.SQLException: Sorry, acquisition timeout!
at io.agroal.pool.ConnectionPool.handlerFromSharedCache(ConnectionPool.java:299)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:253)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
at io.quarkus.hibernate.orm.runtime.customized.QuarkusConnectionProvider.getConnection(QuarkusConnectionProvider.java:23)
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:46)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:113)
... 47 more
2024-05-07 05:43:03,253 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (executor-thread-132) SQL Error: 0, SQLState: null
2024-05-07 05:43:03,253 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (executor-thread-132) Sorry, acquisition timeout!
2024-05-07 05:43:03,254 WARN [org.keycloak.services] (executor-thread-132) KC-SERVICES0013: Failed authentication: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection [Sorry, acquisition timeout!] [n/a]
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:63)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:94)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:116)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:143)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:54)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:153)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:183)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:155)
at org.hibernate.sql.exec.spi.JdbcSelectExecutor.lambda$list$0(JdbcSelectExecutor.java:85)
at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:231)
at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.getResultSet(DeferredResultSetAccess.java:167)
at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.advanceNext(JdbcValuesResultSetImpl.java:218)
at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.processNext(JdbcValuesResultSetImpl.java:98)
at org.hibernate.sql.results.jdbc.internal.AbstractJdbcValues.next(AbstractJdbcValues.java:19)
at org.hibernate.sql.results.internal.RowProcessingStateStandardImpl.next(RowProcessingStateStandardImpl.java:66)
at org.hibernate.sql.results.spi.ListResultsConsumer.consume(ListResultsConsumer.java:202)
at org.hibernate.sql.results.spi.ListResultsConsumer.consume(ListResultsConsumer.java:33)
at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.doExecuteQuery(JdbcSelectExecutorStandardImpl.java:209)
at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.executeQuery(JdbcSelectExecutorStandardImpl.java:83)
at org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:76)
at org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:65)
at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.lambda$new$2(ConcreteSqmSelectQueryPlan.java:137)
at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.withCacheableSqmInterpretation(ConcreteSqmSelectQueryPlan.java:362)
at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.performList(ConcreteSqmSelectQueryPlan.java:303)
at org.hibernate.query.sqm.internal.QuerySqmImpl.doList(QuerySqmImpl.java:509)
at org.hibernate.query.spi.AbstractSelectionQuery.list(AbstractSelectionQuery.java:427)
at org.hibernate.query.Query.getResultList(Query.java:120)
at org.keycloak.models.jpa.JpaUserProvider.getUserByEmail(JpaUserProvider.java:541)
at org.keycloak.storage.UserStorageManager.getUserByEmail(UserStorageManager.java:391)
at org.keycloak.models.cache.infinispan.UserCacheSession.getUserByEmail(UserCacheSession.java:399)
at org.keycloak.userprofile.validator.DuplicateEmailValidator.validate(DuplicateEmailValidator.java:67)
at org.keycloak.userprofile.AttributeValidatorMetadata.validate(AttributeValidatorMetadata.java:80)
at org.keycloak.userprofile.DefaultAttributes.validate(DefaultAttributes.java:178)
at org.keycloak.userprofile.DefaultUserProfile.validate(DefaultUserProfile.java:76)
at org.keycloak.authentication.requiredactions.VerifyUserProfile.evaluateTriggers(VerifyUserProfile.java:63)
at org.keycloak.services.managers.AuthenticationManager.evaluateRequiredAction(AuthenticationManager.java:1353)
at org.keycloak.services.managers.AuthenticationManager.lambda$evaluateRequiredActionTriggers$19(AuthenticationManager.java:1324)
at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
at java.base/java.util.stream.ReferencePipeline.forEachOrdered(ReferencePipeline.java:601)
at org.keycloak.services.managers.AuthenticationManager.evaluateRequiredActionTriggers(AuthenticationManager.java:1324)
at org.keycloak.services.managers.AuthenticationManager.nextRequiredAction(AuthenticationManager.java:1042)
at org.keycloak.authentication.AuthenticationProcessor.nextRequiredAction(AuthenticationProcessor.java:1138)
at org.keycloak.protocol.AuthorizationEndpointBase.handleBrowserAuthenticationRequest(AuthorizationEndpointBase.java:137)
at org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.buildAuthorizationCodeAuthorizationResponse(AuthorizationEndpoint.java:337)
at org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.process(AuthorizationEndpoint.java:202)
at org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.buildGet(AuthorizationEndpoint.java:113)
at org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint$quarkusrestinvoker$buildGet_4b690b27439f19dd29733dc5fd4004f24de0adb6.invoke(Unknown Source)
at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)
at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: java.sql.SQLException: Sorry, acquisition timeout!
at io.agroal.pool.ConnectionPool.handlerFromSharedCache(ConnectionPool.java:299)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:253)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
at io.quarkus.hibernate.orm.runtime.customized.QuarkusConnectionProvider.getConnection(QuarkusConnectionProvider.java:23)
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:46)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:113)
... 63 more
I have checked the DB connection from the container multiple time after seeing this error, connection is fine. If connection is not fine, it shouldn’t work before the API call as well, right?.