Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

not respecting prepareThreshold=0 #742

Closed
davecramer opened this issue Feb 3, 2017 · 7 comments
Closed

not respecting prepareThreshold=0 #742

davecramer opened this issue Feb 3, 2017 · 7 comments

Comments

@davecramer
Copy link
Member

@davecramer davecramer commented Feb 3, 2017

from the jdbc list:

The database connections have preparedThreshold set to 0 as documented in the pgBouncer FAQ (https://pgbouncer.github.io/faq.html#how-to-use-prepared-statements-with-transaction-pooling).

This works with postgresql-jdbc versions 9.4-1205 and 9.4.1208. It does not work in any version since 1208.

I would like to keep packages up-to-date, so any help is much appreciated. Packages are centos 6, pgdg 9.2, and wildfly .tar.gz.

Stack traces and configuration follow below.

Thanks,

Malcolm Studd

The stack trace from 9.4.1212. The reported error is the same in 1211, and I think 1210.

2017-02-02 11:36:11,284 INFO [org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl] (Batch Thread - 3) HHH000010: On release of batch it still contained JDBC statements
2017-02-02 11:36:11,286 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (Batch Thread - 3) SQL Error: 0, SQLState: 26000
2017-02-02 11:36:11,287 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (Batch Thread - 3) Batch entry 0 update instrument001.t0050instrument_symbol set symbol_format_id=1 where instrument_id='FI-144471' and symbol_format_id=1 w
as aborted: ERROR: prepared statement "S_2" does not exist Call getNextException to see other errors in the batch.
2017-02-02 11:36:11,288 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (Batch Thread - 3) SQL Error: 0, SQLState: 26000
2017-02-02 11:36:11,288 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (Batch Thread - 3) ERROR: prepared statement "S_2" does not exist
2017-02-02 11:36:11,293 ERROR [org.hibernate.engine.jdbc.batch.internal.BatchingBatch] (Batch Thread - 3) HHH000315: Exception executing batch [could not execute batch]
2017-02-02 11:36:11,298 ERROR [exchange-sync-FI(4695877) com.recognia.batch.listener.TaskChunkListener] (Batch Thread - 3) Batch chunk exception: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1212)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jberet.runtime.runner.ChunkRunner.doCheckpoint(ChunkRunner.java:529)
at org.jberet.runtime.runner.ChunkRunner.readProcessWriteItems(ChunkRunner.java:307)
at org.jberet.runtime.runner.ChunkRunner.run(ChunkRunner.java:192)
at org.jberet.runtime.runner.StepExecutionRunner.runBatchletOrChunk(StepExecutionRunner.java:212)
at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:139)
at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164)
at org.jberet.runtime.runner.CompositeExecutionRunner.runJobElement(CompositeExecutionRunner.java:128)
at org.jberet.runtime.runner.CompositeExecutionRunner.runDecision(CompositeExecutionRunner.java:176)
at org.jberet.runtime.runner.CompositeExecutionRunner.runJobElement(CompositeExecutionRunner.java:134)
at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:191)
at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164)
at org.jberet.runtime.runner.CompositeExecutionRunner.runFromHeadOrRestartPoint(CompositeExecutionRunner.java:88)
at org.jberet.runtime.runner.JobExecutionRunner.run(JobExecutionRunner.java:54)
at org.wildfly.jberet.services.BatchEnvironmentService$WildFlyBatchEnvironment$1.run(BatchEnvironmentService.java:139)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: could not execute batch
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1677)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1683)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl$CallbackExceptionMapperImpl.mapManagedFlushFailure(AbstractEntityManagerImpl.java:1882)
at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:119)
at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:50)
at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.beforeCompletion(JCAOrderedLastSynchronizationList.java:116)
at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:371)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200)
... 22 more
Caused by: org.hibernate.exception.GenericJDBCException: could not execute batch
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:126)
at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:136)
at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.addToBatch(BatchingBatch.java:98)
at org.hibernate.persister.collection.OneToManyPersister.writeIndex(OneToManyPersister.java:251)
at org.hibernate.persister.collection.OneToManyPersister.insertRows(OneToManyPersister.java:192)
at org.hibernate.action.internal.CollectionUpdateAction.execute(CollectionUpdateAction.java:102)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:465)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:351)
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:350)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56)
at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1258)
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:425)
at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:114)
... 29 more
Caused by: java.sql.BatchUpdateException: Batch entry 0 update instrument001.t0050instrument_symbol set symbol_format_id=1 where instrument_id='FI-144471' and symbol_format_id=1 was aborted: ERROR: prepared statement "S_2" does not exist Call getNextException to see other errors in the batch.
at org.postgresql.jdbc.BatchResultHandler.handleCompletion(BatchResultHandler.java:163)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:471)
at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:793)
at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1659)
at org.jboss.jca.adapters.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:1174)
at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:127)
... 40 more
Caused by: org.postgresql.util.PSQLException: ERROR: prepared statement "S_2" does not exist
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2455)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2155)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:460)
... 44 more

The stack trace from 9.4.1209

2017-02-02T12:02:26.883: ERROR: [com.recognia.batch.writer.instrument.InstrumentActionCollectionWriter] Item writer exception: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: could not execute batch
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1677)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1683)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:1338)
at org.hibernate.jpa.internal.QueryImpl.beforeQuery(QueryImpl.java:484)
at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:447)
at com.recognia.common.data.ClearInstrumentData.clearDatabaseData(ClearInstrumentData.java:47)
at com.recognia.common.data.ClearInstrumentData.clearData(ClearInstrumentData.java:33)
at com.recognia.batch.writer.instrument.InstrumentActionCollectionWriter.deleteInstrument(InstrumentActionCollectionWriter.java:116)
at com.recognia.batch.writer.instrument.InstrumentActionCollectionWriter.doWriteItems(InstrumentActionCollectionWriter.java:69)
at com.recognia.batch.writer.AbstractItemWriter.writeItems(AbstractItemWriter.java:125)
at org.jberet.runtime.runner.ChunkRunner.doCheckpoint(ChunkRunner.java:512)
at org.jberet.runtime.runner.ChunkRunner.readProcessWriteItems(ChunkRunner.java:307)
at org.jberet.runtime.runner.ChunkRunner.run(ChunkRunner.java:192)
at org.jberet.runtime.runner.StepExecutionRunner.runBatchletOrChunk(StepExecutionRunner.java:212)
at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:139)
at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164)
at org.jberet.runtime.runner.CompositeExecutionRunner.runJobElement(CompositeExecutionRunner.java:128)
at org.jberet.runtime.runner.CompositeExecutionRunner.runDecision(CompositeExecutionRunner.java:176)
at org.jberet.runtime.runner.CompositeExecutionRunner.runJobElement(CompositeExecutionRunner.java:134)
at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:191)
at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164)
at org.jberet.runtime.runner.CompositeExecutionRunner.runFromHeadOrRestartPoint(CompositeExecutionRunner.java:88)
at org.jberet.runtime.runner.JobExecutionRunner.run(JobExecutionRunner.java:54)
at org.wildfly.jberet.services.BatchEnvironmentService$WildFlyBatchEnvironment$1.run(BatchEnvironmentService.java:139)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: org.hibernate.exception.GenericJDBCException: could not execute batch
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:126)
at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:136)
at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:114)
at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:163)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.getBatch(JdbcCoordinatorImpl.java:215)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3102)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3581)
at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:104)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:465)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:351)
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:350)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56)
at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1258)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:1335)
... 27 more
Caused by: java.sql.BatchUpdateException: Batch entry 0 /* insert com.recognia.model.eventdb.instrument.Symbol */ insert into instrument001.t0050instrument_symbol (symbol, instrument_id, symbol_format_id) values ('S0152', 'ES-4385622', 1) was aborted. Call getNextException to see the cause.
at org.postgresql.jdbc.BatchResultHandler.handleError(BatchResultHandler.java:137)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2024)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:377)
at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:1026)
at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1661)
at org.jboss.jca.adapters.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:1174)
at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:127)
... 39 more

a datasource from wildfly domain.xml

jdbc:postgresql://${recognia.datasource.eventdb001.host}:${recognia.datasource.eventdb001.port}/${recognia.datasource.eventdb001.name.work}
org.postgresql.Driver

0

postgres

TRANSACTION_READ_COMMITTED

1
300
true

IdleConnections

${recognia.datasource.eventdb001.user}

${recognia.datasource.eventdb001.password}



select 1
true

true

5000




1


true

false

@jorsol
Copy link
Member

@jorsol jorsol commented Feb 8, 2017

This should be fixed by #690

@davecramer davecramer closed this Mar 19, 2017
@davecramer
Copy link
Member Author

@davecramer davecramer commented Mar 19, 2017

fixed by #690

@alokob
Copy link

@alokob alokob commented Feb 20, 2020

@davecramer , @jorsol I am using postgresql-42.0.0.jar and postgres-server version 9.1 , with PgBouncer version 1.10. This issue still exists.
I have prepareThreshold=0 set in connection-url ,but still preparestatments are failing

@davecramer
Copy link
Member Author

@davecramer davecramer commented Feb 20, 2020

@alokob a few things.

9.1 is EOL
42.0.0 is a few years old.

Can you update the driver and let me know if:

  1. it is still happening
  2. what the error is ?

@alokob
Copy link

@alokob alokob commented Feb 21, 2020

@davecramer Thanks for reply.

We have upgraded Postgres server to 9.2 but still getting same error.
Also please note that its not the case that this issue occurs consistently , it occurs intermittently.

LOGS
`errors in the batch.
2020-02-20 06:31:44 WARN JDBCExceptionReporter:71 - SQL Error: 0, SQLState: 26000
2020-02-20 06:31:44 ERROR JDBCExceptionReporter:72 - ERROR: prepared statement "S_2" does not exist
2020-02-20 06:31:44 ERROR AbstractFlushingEventListener:277 - Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:82)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:70)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:181)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:226)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:137)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:274)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:730)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:324)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:86)'

Also note PgBouncer configs we have ,
pgbouncer.ini
`[databases]
db1 = host=pgdb dbname=db1 pool_mode=transaction

[pgbouncer]
listen_addr = *
listen_port = 6432
auth_type = plain
auth_file = /pgbouncer-1.10.0/userlist.txt
admin_users = abc
ignore_startup_parameters = extra_float_digits
default_pool_size=200
max_client_conn=10000
max_db_connections = 200
reserve_pool_size = 25
server_reset_query = DISCARD ALL ;
logfile = /var/log/pgbouncer/pgbouncer.log
pidfile = /var/log/pgbouncer/pgbouncer.pid`

@davecramer
Copy link
Member Author

@davecramer davecramer commented Feb 21, 2020

Please upgrade the driver. Looking at

public void testBatchWithPrepareThreshold0() throws SQLException {

suggests that it should work as advertised.

@alokob
Copy link

@alokob alokob commented Feb 21, 2020

@davecramer Ok will try after upgrading driver.

Also just wanted to confirm if PgBouncer config key "server_reset_query = DISCARD ALL ;" should be used with transaction mode or not.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
3 participants