pgjdbc/pgjdbc GitHub issues and pull requests (mirror)
help / color / mirror / Atom feed[pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
9+ messages / 2 participants
[nested] [flat]
* [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 07:46 "papegaaij (@papegaaij)" <[email protected]>
0 siblings, 0 replies; 9+ messages in thread
From: papegaaij (@papegaaij) @ 2025-07-09 07:46 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
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 [email protected]//org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:202)
at [email protected]//org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:375)
at [email protected]//org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:143)
< cut >
at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:256)
at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:101)
at [email protected]//io.undertow.server.Connectors.executeRootHandler(Connectors.java:395)
at [email protected]//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:861)
at [email protected]//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at [email protected]//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
at [email protected]//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
at [email protected]//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
at [email protected]//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 [email protected]//org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:63)
at [email protected]//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108)
at [email protected]//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:94)
at [email protected]//org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:268)
at [email protected]//org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.getResultSet(DeferredResultSetAccess.java:171)
at [email protected]//org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.<init>(JdbcValuesResultSetImpl.java:74)
at [email protected]//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.resolveJdbcValuesSource(JdbcSelectExecutorStandardImpl.java:355)
at [email protected]//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.doExecuteQuery(JdbcSelectExecutorStandardImpl.java:137)
at [email protected]//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.executeQuery(JdbcSelectExecutorStandardImpl.java:102)
at [email protected]//org.hibernate.sql.exec.spi.JdbcSelectExecutor.executeQuery(JdbcSelectExecutor.java:91)
at [email protected]//org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:165)
at [email protected]//org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.lambda$new$1(ConcreteSqmSelectQueryPlan.java:152)
at [email protected]//org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.withCacheableSqmInterpretation(ConcreteSqmSelectQueryPlan.java:442)
at [email protected]//org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.performList(ConcreteSqmSelectQueryPlan.java:362)
at [email protected]//org.hibernate.query.sqm.internal.QuerySqmImpl.doList(QuerySqmImpl.java:380)
at [email protected]//org.hibernate.query.spi.AbstractSelectionQuery.list(AbstractSelectionQuery.java:143)
at [email protected]//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 [email protected]//org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:35)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at [email protected]//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:62)
at [email protected]//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:72)
at [email protected]//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:85)
at [email protected]//org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:46)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:26)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:30)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:28)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at [email protected]//org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:35)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:34)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:39)
at [email protected]//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at [email protected]//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 [email protected]//org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2734)
at [email protected]//org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2421)
at [email protected]//org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:372)
at [email protected]//org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:518)
at [email protected]//org.postgresql.jdbc.PgStatement.execute(PgStatement.java:435)
at [email protected]//org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:196)
at [email protected]//org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:139)
at [email protected]//org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:504)
at [email protected]//org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:250)
... 277 more
```
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 08:23 "vlsi (@vlsi)" <[email protected]>
7 siblings, 0 replies; 9+ messages in thread
From: vlsi (@vlsi) @ 2025-07-09 08:23 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
For reference, the error message comes from pgpool2: https://github.com/pgpool/pgpool2/blob/864a1fe114a6af283804f1c3e231ed697a0a8573/src/protocol/pool_pr...
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 08:33 "vlsi (@vlsi)" <[email protected]>
7 siblings, 0 replies; 9+ messages in thread
From: vlsi (@vlsi) @ 2025-07-09 08:33 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
Here's the commit: https://github.com/pgpool/pgpool2/commit/240c668d120065534b1d298d6facc86839fcbab9*
I think the issue duplicates https://github.com/pgjdbc/pgjdbc/issues/3107, so it is not like a "regression from 42.7.5 to 45.7.7", but it sounds like a long-standing "simple vs extended queries vs sync" issue to me, which probably surfaced by using `pgpool2 + pgjdbc autosave`.
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 08:38 "papegaaij (@papegaaij)" <[email protected]>
7 siblings, 0 replies; 9+ messages in thread
From: papegaaij (@papegaaij) @ 2025-07-09 08:38 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
@vlsi If I'm not mistaken, pgjdbc autosave needs to be enabled explicitly. We do not use autosave, so even though it might be related to the other ticket, the cause must be somewhere else. Also, we are very confident this change was introduced between 42.7.5 and 42.7.7 as we consistently trigger the error on the latter version and do not on the first.
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 08:58 "vlsi (@vlsi)" <[email protected]>
7 siblings, 0 replies; 9+ messages in thread
From: vlsi (@vlsi) @ 2025-07-09 08:58 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
I'm sure the commit that altered the behaviour was https://github.com/pgjdbc/pgjdbc/pull/3655/files#diff-cfe87ac6bfaa171dc41659f7bd2368cf9fc6d6d6531fad...
Effectively, previously many queries were sent as `extended` even though at the driver side the query was like `send query with QUERY_EXECUTE_AS_SIMPLE flag`.
For instance, `connection.isValid()` was coded to use simple queries, and it was using extended in practice, thus it suffered from `prepared statement is not valid` kind of errors.
Good to know you are not using autosave though.
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 10:53 "papegaaij (@papegaaij)" <[email protected]>
7 siblings, 0 replies; 9+ messages in thread
From: papegaaij (@papegaaij) @ 2025-07-09 10:53 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
That does make sense indeed. However, this change now makes it virtually impossible to upgrade PgJDBC for everyone using pgpool-II. The discussion linked in #3107 did not come to a conclusion and the ticket has not seen any activity since it was created. What do you think is the way forward? We cannot stay on 42.7.5 indefinitely nor can we stop using pgpool-II. Do you think this should be addressed in pgpool-II or will this be fixed in an upcoming version of PgJDBC?
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 11:50 "vlsi (@vlsi)" <[email protected]>
7 siblings, 0 replies; 9+ messages in thread
From: vlsi (@vlsi) @ 2025-07-09 11:50 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
Well, the validation was specific to pg-pool, and it is not clear if a missing sync message does any harm for the regular postgresql.
As per my understanding, it should not be that hard to inject the missing sync message at the driver level (it looks like a call to https://github.com/pgjdbc/pgjdbc/blob/master/pgjdbc/src/main/java/org/postgresql/core/v3/QueryExecut...). However, it is not clear if we need to to extra work for transaction semantics.
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 12:01 "vlsi (@vlsi)" <[email protected]>
7 siblings, 0 replies; 9+ messages in thread
From: vlsi (@vlsi) @ 2025-07-09 12:01 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
>The discussion linked in https://github.com/pgjdbc/pgjdbc/issues/3107 did not come to a conclusion
The time is limited, and discussion-like tickets tend to get less attention than user-facing issues.
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message
@ 2025-07-09 12:48 "papegaaij (@papegaaij)" <[email protected]>
7 siblings, 0 replies; 9+ messages in thread
From: papegaaij (@papegaaij) @ 2025-07-09 12:48 UTC (permalink / raw)
To: pgjdbc/pgjdbc <[email protected]>
I totally get the issue with limited time, especially on open source projects like this and I really do not judge the decisions made. I think the PostgreSQL community is great, responsive, open minded and very helpful in many cases. See it from the positive side: the discussion-like ticket has now become a user-facing issue, so it will probably attract some more attention 😄
The problem is that at the moment pgpool-II users are a bit stuck between a rock and a hard place. I've also raised this issue at the pgpool mailing list. IMHO, a decision needs to be made to either support missing syncs or forbid them. In the first case, pgpool needs to be adjusted, in the later case pgjdbc needs to be changed. Unfortunately, I'm not in the position to make this decision, nor can I fix pgpool or pgjdbc as I'm not familiar enough with the details on the protocol.
From the perspective of pgjdbc: would it hurt to do a sync when in extended mode and a simple query is about to be executed?
The discussion in the thread on pgsql-hackers ended with 'it would probably be a good idea to throw an error from the server side'. This is what pgpool is currently doing, but apparently this was never implemented in PostgreSQL itself, otherwise this would most likely have been addressed already in pgjdbc.
^ permalink raw reply [nested|flat] 9+ messages in thread
end of thread, other threads:[~2025-07-09 12:48 UTC | newest]
Thread overview: 9+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2025-07-09 07:46 [pgjdbc/pgjdbc] issue #3724: Regression: FATAL: simple query "BEGIN" arrived before ending an extended query message "papegaaij (@papegaaij)" <[email protected]>
2025-07-09 08:23 ` "vlsi (@vlsi)" <[email protected]>
2025-07-09 08:33 ` "vlsi (@vlsi)" <[email protected]>
2025-07-09 08:38 ` "papegaaij (@papegaaij)" <[email protected]>
2025-07-09 08:58 ` "vlsi (@vlsi)" <[email protected]>
2025-07-09 10:53 ` "papegaaij (@papegaaij)" <[email protected]>
2025-07-09 11:50 ` "vlsi (@vlsi)" <[email protected]>
2025-07-09 12:01 ` "vlsi (@vlsi)" <[email protected]>
2025-07-09 12:48 ` "papegaaij (@papegaaij)" <[email protected]>
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox