[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 17:41:43 EDT 2018
Interesting. Looking over the history, I did see a huge memory jump around
the time when the exception occurred. Is there a memory leak somewhere?
On Fri, Aug 3, 2018 at 1:58 PM, Joy Kent <joy at autonomic.ai> wrote:
> 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</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 at 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 at lists.jboss.org
>> https://lists.jboss.org/mailman/listinfo/keycloak-user
>>
>
>
More information about the keycloak-user
mailing list