search

geonetwork / core-geonetwork

GeoNetwork is a catalog application to manage spatially referenced resources. It provides powerful metadata editing and search functions as well as an interactive web map viewer. It is currently used in numerous Spatial Data Infrastructure initiatives across the world.
http://geonetwork-opensource.org/
GNU General Public License v2.0
410 stars 487 forks source link

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

Open rockliffelewis opened 2 years ago

rockliffelewis commented 2 years ago

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):

jodygarnett commented 6 months ago

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

jodygarnett commented 6 months ago

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