Message-ID: From: "papegaaij (@papegaaij)" To: "pgjdbc/pgjdbc" Date: Wed, 09 Jul 2025 07:46:00 +0000 Subject: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message List-Id: X-GitHub-Author-Id: 191540 X-GitHub-Author-Login: papegaaij X-GitHub-Issue: 3724 X-GitHub-Repo: pgjdbc/pgjdbc X-GitHub-State: closed X-GitHub-Type: issue X-GitHub-Url: https://github.com/pgjdbc/pgjdbc/issues/3724 Content-Type: text/plain; charset=utf-8 Since the upgrade to 42.7.7 we are experiencing intermittent errors on our database connections. The error reads `FATAL: simple query "BEGIN" arrived before ending an extended query message`. This errors is emitted by pgpool-II, so it could also be a bug in pgpool-II triggered by this new version of PgJDBC. However, the error gives me the impression that a previous query is not closed properly, which seems to point to PgJDBC. Unfortunately, we don't have a path to reproduction. We've observed the error about 10 times every hour, and it stopped the moment we downgraded PgJDBC to 42.7.5, so we are very sure the trigger is in PgJDBC. **Environment** PgJDBC 42.7.7 (broken) 42.7.5 (ok) PostgreSQL 17.5 on Alpine 3.21.3 in docker pgpool-II 4.6.2 OpenJDK Runtime Environment Temurin-21.0.7+6 WildFly 36.0.1 **Stacktrace** ``` 2025-07-08T06:41:22+02:00 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (backend task-145) SQL Error: 0, SQLState: XX000 2025-07-08T06:41:22+02:00 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (backend task-145) FATAL: simple query "BEGIN" arrived before ending an extended query message 2025-07-08T06:41:22+02:00 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (backend task-145) SQL Error: 0, SQLState: 08006 2025-07-08T06:41:22+02:00 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (backend task-145) An I/O error occurred while sending to the backend. 2025-07-08T06:41:22+02:00 ERROR [org.jboss.as.ejb3.invocation] (backend task-145) WFLYEJB0034: Jakarta Enterprise Beans Invocation failed on component VaultRecordDAO for method public java.util.List nl.topicus.cobra.dao.data.AbstractDAO.get(int,int,nl.topicus.cobra.dao.filter.AbstractZoekFilter): jakarta.ejb.EJBTransactionRolledbackException: JDBC exception executing SQL [select pr1_0.id,pr1_0.color,pr1_0.createdAt,pr1_0.createdBy,pr1_0.derived,pr1_0.endDate,pr1_0.filename,pr1_0.lastModifiedAt,pr1_0.lastmodifiedby,pr1_0.metadata,pr1_0.name,pr1_0.parent,pr1_0.recordKey,pr1_0.shareEndTime,pr1_0.url,pr1_0.username,pr1_0.uuid,pr1_0.vault,pr1_0.version,pr1_0.warningPeriod from VAULT_RECORD pr1_0 where (pr1_0.vault in ((select p2_0.vault from KHGROUP p2_0 where (p2_0.organizationalunit=?) and (p2_0.id=?) and p2_0.id=?)) or pr1_0.vault in ((select vs1_0.vault from CLIENT_APPLICATION pc1_0 join KHGROUP o1_0 on o1_0.id=pc1_0.owner join VAULT_SECRETS vs1_0 on vs1_0.id=pc1_0.vaultsecrets where (o1_0.organizationalunit=? or pc1_0.id in ((select puca1_0.clientapplication from ORGANIZATIONAL_UNIT_CLIENT_APPLICATION puca1_0 where puca1_0.organizationalunit=?))) and (pc1_0.id in ((select pc2_0.client from GROUP_CLIENT pc2_0 where pc2_0.khgroup=?)) or pc1_0.id=?) and pc1_0.id=? and pc1_0.DTYPE='POAuth2Client'))) and pr1_0.uuid=? order by pr1_0.id fetch first ? rows only] [FATAL: simple query "BEGIN" arrived before ending an extended query message] [n/a] at org.jboss.as.ejb3@36.0.1.Final//org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:202) at org.jboss.as.ejb3@36.0.1.Final//org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:375) at org.jboss.as.ejb3@36.0.1.Final//org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:143) < cut > at io.undertow.servlet@2.3.18.Final//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:256) at io.undertow.servlet@2.3.18.Final//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:101) at io.undertow.core@2.3.18.Final//io.undertow.server.Connectors.executeRootHandler(Connectors.java:395) at io.undertow.core@2.3.18.Final//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:861) at org.jboss.threads@2.4.0.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35) at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990) at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486) at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377) at org.jboss.xnio@3.8.16.Final//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282) at java.base/java.lang.Thread.run(Unknown Source) Caused by: org.hibernate.exception.GenericJDBCException: JDBC exception executing SQL [select pr1_0.id,pr1_0.color,pr1_0.createdAt,pr1_0.createdBy,pr1_0.derived,pr1_0.endDate,pr1_0.filename,pr1_0.lastModifiedAt,pr1_0.lastmodifiedby,pr1_0.metadata,pr1_0.name,pr1_0.parent,pr1_0.recordKey,pr1_0.shareEndTime,pr1_0.url,pr1_0.username,pr1_0.uuid,pr1_0.vault,pr1_0.version,pr1_0.warningPeriod from VAULT_RECORD pr1_0 where (pr1_0.vault in ((select p2_0.vault from KHGROUP p2_0 where (p2_0.organizationalunit=?) and (p2_0.id=?) and p2_0.id=?)) or pr1_0.vault in ((select vs1_0.vault from CLIENT_APPLICATION pc1_0 join KHGROUP o1_0 on o1_0.id=pc1_0.owner join VAULT_SECRETS vs1_0 on vs1_0.id=pc1_0.vaultsecrets where (o1_0.organizationalunit=? or pc1_0.id in ((select puca1_0.clientapplication from ORGANIZATIONAL_UNIT_CLIENT_APPLICATION puca1_0 where puca1_0.organizationalunit=?))) and (pc1_0.id in ((select pc2_0.client from GROUP_CLIENT pc2_0 where pc2_0.khgroup=?)) or pc1_0.id=?) and pc1_0.id=? and pc1_0.DTYPE='POAuth2Client'))) and pr1_0.uuid=? order by pr1_0.id fetch first ? rows only] [FATAL: simple query "BEGIN" arrived before ending an extended query message] [n/a] at org.hibernate@6.6.7.Final//org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:63) at org.hibernate@6.6.7.Final//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108) at org.hibernate@6.6.7.Final//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:94) at org.hibernate@6.6.7.Final//org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:268) at org.hibernate@6.6.7.Final//org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.getResultSet(DeferredResultSetAccess.java:171) at org.hibernate@6.6.7.Final//org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.(JdbcValuesResultSetImpl.java:74) at org.hibernate@6.6.7.Final//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.resolveJdbcValuesSource(JdbcSelectExecutorStandardImpl.java:355) at org.hibernate@6.6.7.Final//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.doExecuteQuery(JdbcSelectExecutorStandardImpl.java:137) at org.hibernate@6.6.7.Final//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.executeQuery(JdbcSelectExecutorStandardImpl.java:102) at org.hibernate@6.6.7.Final//org.hibernate.sql.exec.spi.JdbcSelectExecutor.executeQuery(JdbcSelectExecutor.java:91) at org.hibernate@6.6.7.Final//org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:165) at org.hibernate@6.6.7.Final//org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.lambda$new$1(ConcreteSqmSelectQueryPlan.java:152) at org.hibernate@6.6.7.Final//org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.withCacheableSqmInterpretation(ConcreteSqmSelectQueryPlan.java:442) at org.hibernate@6.6.7.Final//org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.performList(ConcreteSqmSelectQueryPlan.java:362) at org.hibernate@6.6.7.Final//org.hibernate.query.sqm.internal.QuerySqmImpl.doList(QuerySqmImpl.java:380) at org.hibernate@6.6.7.Final//org.hibernate.query.spi.AbstractSelectionQuery.list(AbstractSelectionQuery.java:143) at org.hibernate@6.6.7.Final//org.hibernate.query.Query.getResultList(Query.java:120) at deployment.keyhub-ear.ear//nl.topicus.cobra.dao.data.AbstractDAO.lambda$get$9(AbstractDAO.java:728) at deployment.keyhub-ear.ear//nl.topicus.cobra.dao.data.AbstractDAO.timed(AbstractDAO.java:1478) at deployment.keyhub-ear.ear//nl.topicus.cobra.dao.data.AbstractDAO.get(AbstractDAO.java:727) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(Unknown Source) at java.base/java.lang.reflect.Method.invoke(Unknown Source) at org.jboss.as.ee@36.0.1.Final//org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:35) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509) at org.jboss.as.weld.common@36.0.1.Final//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:62) at org.jboss.as.weld.common@36.0.1.Final//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:72) at org.jboss.as.weld.common@36.0.1.Final//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:85) at org.jboss.as.ee@36.0.1.Final//org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:46) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3@36.0.1.Final//org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:26) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.jpa@36.0.1.Final//org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:30) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.wildfly.concurrency@36.0.1.Final//org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:28) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53) at org.jboss.as.ee@36.0.1.Final//org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:35) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3@36.0.1.Final//org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:34) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3@36.0.1.Final//org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:39) at org.jboss.invocation@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) at org.jboss.as.ejb3@36.0.1.Final//org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:184) ... 235 more Caused by: org.postgresql.util.PSQLException: FATAL: simple query "BEGIN" arrived before ending an extended query message at org.postgresql.jdbc@42.7.7//org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2734) at org.postgresql.jdbc@42.7.7//org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2421) at org.postgresql.jdbc@42.7.7//org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:372) at org.postgresql.jdbc@42.7.7//org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:518) at org.postgresql.jdbc@42.7.7//org.postgresql.jdbc.PgStatement.execute(PgStatement.java:435) at org.postgresql.jdbc@42.7.7//org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:196) at org.postgresql.jdbc@42.7.7//org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:139) at org.jboss.ironjacamar.jdbcadapters@3.0.13.Final//org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:504) at org.hibernate@6.6.7.Final//org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:250) ... 277 more ```