Re: [keycloak-user] ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-21) This connection has been closed.

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(a)agi.com&gt; 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(a)lists.jboss.org [ > keycloak-user-bounces(a)lists.jboss.org] on behalf of Joy Kent [ > joy(a)autonomic.ai] > Sent: Friday, August 3, 2018 2:30 PM > To: keycloak-user(a)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</b > ackground-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</b > ackground-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@76b2b731 >: > javax.persistence.PersistenceException: > org.hibernate.exception.JDBCConnectionException: could not prepare > statement > at > org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(Abst > ractEntityManagerImpl.java:1692) > at > org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(Abst > ractEntityManagerImpl.java:1602) > at > org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(Abst > ractEntityManagerImpl.java:1608) > at > org.hibernate.jpa.internal.EntityManagerImpl$CallbackExcepti > onMapperImpl.mapManagedFlushFailure(EntityManagerImpl.java:235) > at > org.hibernate.internal.SessionImpl.flushBeforeTransactionCom > pletion(SessionImpl.java:3163) > at > org.hibernate.internal.SessionImpl.beforeTransactionCompleti > on(SessionImpl.java:2352) > at > org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.befor > eTransactionCompletion(JdbcCoordinatorImpl.java:491) > at > org.hibernate.resource.transaction.backend.jta.internal.JtaT > ransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoo > rdinatorImpl.java:316) > at > org.hibernate.resource.transaction.backend.jta.internal. > synchronization.SynchronizationCallbackCoordinatorNonTrackin > gImpl.beforeCompletion(SynchronizationCallbackCoordinatorNon > TrackingImpl.java:47) > at > org.hibernate.resource.transaction.backend.jta.internal. > synchronization.RegisteredSynchronization.beforeCompletion(R > egisteredSynchronization.java:37) > at > org.wildfly.transaction.client.AbstractTransaction.performCo > nsumer(AbstractTransaction.java:209) > at > org.wildfly.transaction.client.AbstractTransaction.performCo > nsumer(AbstractTransaction.java:220) > at > org.wildfly.transaction.client.AbstractTransaction$Associati > ngSynchronization.beforeCompletion(AbstractTransaction.java:265) > at > com.arjuna.ats.internal.jta.resources.arjunacore.Synchroniza > tionImple.beforeCompletion(SynchronizationImple.java:76) > at > com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.before > Completion(TwoPhaseCoordinator.java:368) > at > com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(Tw > oPhaseCoordinator.java:91) > at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java: > 162) > at > com.arjuna.ats.internal.jta.transaction.arjunacore.Transacti > onImple.commitAndDisassociate(TransactionImple.java:1289) > at > com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTrans > action.commit(BaseTransaction.java:126) > at > com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate. > commit(BaseTransactionManagerDelegate.java:89) > at > org.wildfly.transaction.client.LocalTransaction.commitAndDis > sociate(LocalTransaction.java:73) > at > org.wildfly.transaction.client.ContextTransactionManager.com > mit(ContextTransactionManager.java:71) > at > org.keycloak.transaction.JtaTransactionWrapper.commit(JtaTra > nsactionWrapper.java:92) > at > org.keycloak.services.DefaultKeycloakTransactionManager. > commit(DefaultKeycloakTransactionManager.java:136) > at > org.keycloak.services.filters.KeycloakTransactionCommitter.f > ilter(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.Transacti > onImple.commitAndDisassociate(TransactionImple.java:1289) > at > com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTrans > action.commit(BaseTransaction.java:126) > at > com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate. > commit(BaseTransactionManagerDelegate.java:89) > at > org.wildfly.transaction.client.LocalTransaction.commitAndDis > sociate(LocalTransaction.java:73) > at > org.wildfly.transaction.client.ContextTransactionManager.com > mit(ContextTransactionManager.java:71) > at > org.keycloak.transaction.JtaTransactionWrapper.commit(JtaTra > nsactionWrapper.java:92) > at > org.keycloak.services.DefaultKeycloakTransactionManager. > commit(DefaultKeycloakTransactionManager.java:136) > at > org.keycloak.services.filters.KeycloakTransactionCommitter.f > ilter(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.StandardSQLExceptionConvert > er.convert(StandardSQLExceptionConverter.java:42) > at > org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(Sql > ExceptionHelper.java:111) > at > org.hibernate.engine.jdbc.internal.StatementPreparerImpl$Sta > tementPreparationTemplate.prepareStatement(StatementPreparer > Impl.java:182) > at > org.hibernate.engine.jdbc.internal.StatementPreparerImpl.pre > pareStatement(StatementPreparerImpl.java:78) > at > org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.b > uildBatchStatement(AbstractBatchImpl.java:136) > at > org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.g > etBatchStatement(AbstractBatchImpl.java:125) > at > org.hibernate.persister.entity.AbstractEntityPersister.inser > t(AbstractEntityPersister.java:2980) > at > org.hibernate.persister.entity.AbstractEntityPersister.inser > t(AbstractEntityPersister.java:3499) > at > org.hibernate.action.internal.EntityInsertAction.execute(Ent > ityInsertAction.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.p > erformExecutions(AbstractFlushingEventListener.java:337) > at > org.hibernate.event.internal.DefaultFlushEventListener.onFlu > sh(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.flushBeforeTransactionCom > pletion(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.doP > repareStatement(BaseWrapperManagedConnection.java:757) > at > org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.pre > pareStatement(BaseWrapperManagedConnection.java:743) > at > org.jboss.jca.adapters.jdbc.WrappedConnection.prepareStateme > nt(WrappedConnection.java:454) > at > org.hibernate.engine.jdbc.internal.StatementPreparerImpl$1.d > oPrepare(StatementPreparerImpl.java:87) > at > org.hibernate.engine.jdbc.internal.StatementPreparerImpl$Sta > tementPreparationTemplate.prepareStatement(StatementPreparer > Impl.java:172) > ... 85 more > _______________________________________________ > keycloak-user mailing list > keycloak-user(a)lists.jboss.org > https://lists.jboss.org/mailman/listinfo/keycloak-user >