[keycloak-user] ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-21) This connection has been closed.
Joy Kent
joy at autonomic.ai
Fri Aug 3 16:58:00 EDT 2018
Hi Peter,
Thanks for your suggestions. I haven't checked the memory usage around that
time. I will check that and report back.
Thanks,
Joy
On Fri, Aug 3, 2018 at 12:56 PM, Nalyvayko, Peter <pnalyvayko at agi.com>
wrote:
> tl;dr :)
>
> You may want to check if JVM is running out of memory, we've seen it
> happen before and the effects were similar.
> My 0.02 cents
> Regards,
> Peter
>
> ________________________________________
> From: keycloak-user-bounces at lists.jboss.org [keycloak-user-bounces at lists.
> jboss.org] on behalf of Joy Kent [joy at autonomic.ai]
> Sent: Friday, August 3, 2018 2:30 PM
> To: keycloak-user at lists.jboss.org
> Subject: [keycloak-user] ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper]
> (default task-21) This connection has been closed.
>
> We have a keycloak 3.4.3.Final cluster with two PostgreSQL databases, one
> for keycloak, and the other for user federation storage. Both keycloak and
> user federation PostgreSQL databases are running with AWS RDS instances.
>
> Recently, we noticed that keycloak continuously threw exceptions when the
> user federation PostgreSQL database did a MultiAZ region failover, and
> became not usable. The exception snippet will be attached below. I have
> searched around, but didn't find the answer.
>
> This is our keycloak Database configuration:
>
> <datasource jndi-name="java:jboss/datasources/KeycloakDS"
> pool-name="KeycloakDS" enabled="true" use-java-context="true"
> use-ccm="true">
>
> <connection-url>jdbc:postgresql://${env.POSTGRES_
> PORT_5432_TCP_ADDR}:${env.POSTGRES_PORT_5432_TCP_PORT:
> 5432}/${env.POSTGRES_DATABASE:keycloak}</connection-url>
> <driver>postgresql</driver>
> <pool>
> <flush-strategy>IdleConnections</flush-strategy>
> </pool>
> <security>
> <user-name>${env.POSTGRES_
> USER:keycloak}</user-name>
>
> <password>${env.POSTGRES_PASSWORD:password}</password>
> </security>
> <validation>
> <check-valid-connection-sql>SELECT
> 1</check-valid-connection-sql>
> <background-validation>true</
> background-validation>
>
> <background-validation-millis>60000</background-validation-millis>
> </validation>
> </datasource>
>
> The user federation Database configuration looks like this:
>
> <xa-datasource jndi-name="java:jboss/datasources/IamDS"
> pool-name="IamDS" enabled="true" use-java-context="true" use-ccm="false">
> <xa-datasource-property name="ServerName">
> ${env.IAM_DB_HOST}
> </xa-datasource-property>
> <xa-datasource-property name="PortNumber">
> ${env.IAM_DB_TCP_PORT:5432}
> </xa-datasource-property>
> <xa-datasource-property name="DatabaseName">
> ${env.IAM_DB_DATABASE:iam}
> </xa-datasource-property>
> <driver>postgresql</driver>
> <xa-pool>
>
> <min-pool-size>${env.IAM_XA_POOL_MIN_SIZE:5}</min-pool-size>
>
> <max-pool-size>${env.IAM_XA_POOL_MAX_SIZE:100}</max-pool-size>
> <prefill>false</prefill>
> </xa-pool>
> <security>
> <user-name>${env.IAM_POSTGRES_
> USER:user}</user-name>
>
> <password>${env.IAM_POSTGRES_PASSWORD:password}</password>
> </security>
> <validation>
> <check-valid-connection-sql>SELECT
> 1</check-valid-connection-sql>
> <background-validation>true</
> background-validation>
>
> <background-validation-millis>60000</background-validation-millis>
> </validation>
> </xa-datasource>
>
> The driver is:
>
> <drivers>
> <driver name="postgresql" module="org.postgresql.jdbc">
>
> <xa-datasource-class>org.postgresql.xa.PGXADataSource</
> xa-datasource-class>
> </driver>
> </drivers>
>
> I found a page
> https://access.redhat.com/documentation/en-us/red_hat_
> jboss_enterprise_application_platform/7.0/html/configuration_guide/
> datasource_management,
> which seems to indicate that exception-sorter is important:
>
> To configure database connection validation, you specify the validation
> > timing method (when the validation occurs), the validation mechanism (how
> > the validation is performed), and the exception sorter (how exceptions
> are
> > handled).
>
>
> Is the exception-sorter the missing configuration? I have tried this
> change, which seems to "fix" the problem. But by looking at the code, I
> can't tell how this can solve the problem.
>
> Does anyone know where might be wrong? Thanks a lot for your help!
>
> =====================
>
> The exception snippet is as follows:
>
> ESC[0mESC[0m04:44:55,502 INFO [org.keycloak.events] (default task-21)
> type=CLIENT_LOGIN, realmId=xxxxxxxxxxx, clientId=xxxxxxxxxx,
> userId=xxxxxxxxxxxx, ipAddress=100.96.4.0, token_id
> =xxxxxxxxxxxx, grant_type=client_credentials, refresh_token_type=Refresh,
> refresh_token_id=xxxxxxxxxx, client_auth_method=client-secret,
> username=xxxxxxxxxxx
> ESC[0mESC[33m04:44:55,503 WARN
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-21) SQL
> Error: 0, SQLState: 08003
> ESC[0mESC[31m04:44:55,503 ERROR
> [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-21) This
> connection has been closed.
> ESC[0mESC[33m04:44:55,503 WARN [com.arjuna.ats.arjuna] (default task-21)
> ARJUNA012125: TwoPhaseCoordinator.beforeCompletion - failed for
> SynchronizationImple< 0:ffff646043f0:2ee9e692:5b425ae8:2c012df,
> org.wildfly.transaction.client.AbstractTran
> saction$AssociatingSynchronization at 76b2b731 >:
> javax.persistence.PersistenceException:
> org.hibernate.exception.JDBCConnectionException: could not prepare
> 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.convert(
> AbstractEntityManagerImpl.java:1608)
> at
> org.hibernate.jpa.internal.EntityManagerImpl$CallbackExceptionMapperImpl.
> mapManagedFlushFailure(EntityManagerImpl.java:235)
> at
> org.hibernate.internal.SessionImpl.flushBeforeTransactionCompleti
> on(SessionImpl.java:3163)
> at
> org.hibernate.internal.SessionImpl.beforeTransactionCompletion(
> SessionImpl.java:2352)
> at
> org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.
> beforeTransactionCompletion(JdbcCoordinatorImpl.java:491)
> at
> org.hibernate.resource.transaction.backend.jta.internal.
> JtaTransactionCoordinatorImpl.beforeCompletion(
> JtaTransactionCoordinatorImpl.java:316)
> at
> org.hibernate.resource.transaction.backend.jta.internal.synchronization.
> SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(
> SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
> at
> org.hibernate.resource.transaction.backend.jta.internal.synchronization.
> RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.
> java:37)
> at
> org.wildfly.transaction.client.AbstractTransaction.performConsumer(
> AbstractTransaction.java:209)
> at
> org.wildfly.transaction.client.AbstractTransaction.performConsumer(
> AbstractTransaction.java:220)
> at
> org.wildfly.transaction.client.AbstractTransaction$
> AssociatingSynchronization.beforeCompletion(AbstractTransaction.java:265)
> at
> com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.
> beforeCompletion(SynchronizationImple.java:76)
> at
> com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(
> TwoPhaseCoordinator.java:368)
> at
> com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(
> TwoPhaseCoordinator.java:91)
> at com.arjuna.ats.arjuna.AtomicAction.commit(
> AtomicAction.java:162)
> at
> com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.
> commitAndDisassociate(TransactionImple.java:1289)
> 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)
> at
> org.keycloak.services.DefaultKeycloakTransactionManager.commit(
> DefaultKeycloakTransactionManager.java:136)
> at
> org.keycloak.services.filters.KeycloakTransactionCommitter.filter(
> KeycloakTransactionCommitter.java:43)
> at
> org.jboss.resteasy.core.ServerResponseWriter.executeFilters(
> ServerResponseWriter.java:165)
> at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
> at
> com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.
> commitAndDisassociate(TransactionImple.java:1289)
> 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)
> at
> org.keycloak.services.DefaultKeycloakTransactionManager.commit(
> DefaultKeycloakTransactionManager.java:136)
> at
> org.keycloak.services.filters.KeycloakTransactionCommitter.filter(
> KeycloakTransactionCommitter.java:43)
> at
> org.jboss.resteasy.core.ServerResponseWriter.executeFilters(
> ServerResponseWriter.java:165)
> .....
> Caused by: org.hibernate.exception.JDBCConnectionException: could not
> prepare statement
> at
> org.hibernate.exception.internal.SQLStateConversionDelegate.convert(
> SQLStateConversionDelegate.java:115)
> at
> org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(
> StandardSQLExceptionConverter.java:42)
> at
> org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(
> SqlExceptionHelper.java:111)
> at
> org.hibernate.engine.jdbc.internal.StatementPreparerImpl$
> StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:
> 182)
> at
> org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareStatement(
> StatementPreparerImpl.java:78)
> at
> org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.
> buildBatchStatement(AbstractBatchImpl.java:136)
> at
> org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.
> getBatchStatement(AbstractBatchImpl.java:125)
> at
> org.hibernate.persister.entity.AbstractEntityPersister.insert(
> AbstractEntityPersister.java:2980)
> at
> org.hibernate.persister.entity.AbstractEntityPersister.insert(
> AbstractEntityPersister.java:3499)
> at
> org.hibernate.action.internal.EntityInsertAction.execute(
> EntityInsertAction.java:89)
> at
> org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:589)
> at
> org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:463)
> at
> org.hibernate.event.internal.AbstractFlushingEventListener.
> performExecutions(AbstractFlushingEventListener.java:337)
> at
> org.hibernate.event.internal.DefaultFlushEventListener.onFlush(
> DefaultFlushEventListener.java:39)
> at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1295)
> at
> org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:468)
> at
> org.hibernate.internal.SessionImpl.flushBeforeTransactionCompleti
> on(SessionImpl.java:3159)
> ... 72 more
> Caused by: org.postgresql.util.PSQLException: This connection has been
> closed.
> at
> org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:766)
> at
> org.postgresql.jdbc.PgConnection.prepareStatement(PgConnection.java:1582)
> at
> org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.
> doPrepareStatement(BaseWrapperManagedConnection.java:757)
> at
> org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.prepareStatement(
> BaseWrapperManagedConnection.java:743)
> at
> org.jboss.jca.adapters.jdbc.WrappedConnection.prepareStatement(
> WrappedConnection.java:454)
> at
> org.hibernate.engine.jdbc.internal.StatementPreparerImpl$1.doPrepare(
> StatementPreparerImpl.java:87)
> at
> org.hibernate.engine.jdbc.internal.StatementPreparerImpl$
> StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:
> 172)
> ... 85 more
> _______________________________________________
> keycloak-user mailing list
> keycloak-user at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/keycloak-user
>
More information about the keycloak-user
mailing list