Cannot change transaction read-only property in the middle of a transaction Exceptions with Postgres

[rockliffelewis]

Describe the bug I am running the latest Geonetwork 4 from the published docker containers, configured with an external Postgres 11 instance, and I am seeing quite a lot of exceptions in the debug log relating to setting the JDBC connection to readonly. Geonetwork appears to recover and continue functioning but it is running quite slow.

DEBUG [org.springframework.orm.jpa.JpaTransactionManager] - Creating new transaction with name [org.fao.geonet.repository.GeonetRepositoryImpl.findById]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly DEBUG [org.springframework.orm.jpa.JpaTransactionManager] - Opened new EntityManager [SessionImpl(2059266703<open>)] for JPA transaction DEBUG [org.springframework.jdbc.datasource.DataSourceUtils] - Setting JDBC Connection [964477375, URL=jdbc:postgresql://[server-url]:5433/geonetwork?, UserName=postgres, PostgreSQL JDBC Driver] read-only DEBUG [org.springframework.jdbc.datasource.DataSourceUtils] - Could not set JDBC Connection read-only org.postgresql.util.PSQLException: Cannot change transaction read-only property in the middle of a transaction. at org.postgresql.jdbc.PgConnection.setReadOnly(PgConnection.java:705) at org.apache.commons.dbcp2.DelegatingConnection.setReadOnly(DelegatingConnection.java:561) at org.apache.commons.dbcp2.DelegatingConnection.setReadOnly(DelegatingConnection.java:561) at org.apache.commons.dbcp2.DelegatingConnection.setReadOnly(DelegatingConnection.java:561) at org.springframework.jdbc.datasource.DataSourceUtils.prepareConnectionForTransaction(DataSourceUtils.java:188) at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:175) at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:402) at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400) at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:572) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:360) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:178) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) at com.sun.proxy.$Proxy204.findById(Unknown Source) at org.fao.geonet.kernel.setting.SettingManager.getValue(SettingManager.java:193) at org.fao.geonet.kernel.setting.SettingManager.getValue(SettingManager.java:181) at org.fao.geonet.kernel.setting.SettingManager.getSiteId(SettingManager.java:392) at org.fao.geonet.resources.ResourceFilter$Instance.<init>(ResourceFilter.java:97) at org.fao.geonet.resources.ResourceFilter.doFilter(ResourceFilter.java:72) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) at org.fao.geonet.web.CORSResponseFilter.doFilter(CORSResponseFilter.java:129) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) at org.fao.geonet.monitor.webapp.WebappMetricsFilter.doFilter(WebappMetricsFilter.java:121) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) at org.fao.geonet.monitor.webapp.MetricsRegistryInitializerFilter.doFilter(MetricsRegistryInitializerFilter.java:58) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) at org.fao.geonet.web.XFrameOptionsFilter.doFilter(XFrameOptionsFilter.java:110) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:394) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:209) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271) at jeeves.config.springutil.JeevesDelegatingFilterProxy.doFilter(JeevesDelegatingFilterProxy.java:104) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:201) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:191) at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) at org.eclipse.jetty.server.Server.handle(Server.java:516) at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) at java.lang.Thread.run(Thread.java:750) DEBUG [org.springframework.orm.jpa.JpaTransactionManager] - Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@4dd4f353] DEBUG [org.springframework.orm.jpa.JpaTransactionManager] - Initiating transaction commit DEBUG [org.springframework.orm.jpa.JpaTransactionManager] - Committing JPA transaction on EntityManager [SessionImpl(2059266703<open>)] DEBUG [org.springframework.jdbc.datasource.DataSourceUtils] - Resetting read-only flag of JDBC Connection [964477375, URL=jdbc:postgresql://[server-url]:5433/geonetwork?, UserName=postgres, PostgreSQL JDBC Driver] DEBUG [org.springframework.orm.jpa.JpaTransactionManager] - Closing JPA EntityManager [SessionImpl(2059266703<open>)] after transaction

Desktop (please complete the following information):

• Official Geonetwork 4.0.6 docker image
• Postgres 11 database

[jodygarnett]

I believe this is a duplicate of https://github.com/geonetwork/core-geonetwork/issues/6615

[jodygarnett]

This appears to be either:

a) a coding mistake starting a transaction when when is not needed b) a misconfigured database connection pool c) code not finishing a transaction before returning connection to the pool