Re: postgresql-jdbc driver not respecting prepareThreshold=0

I think the fix has already been merged in
https://github.com/pgjdbc/pgjdbc/pull/690

Malcolm, could you please test if pgjdbc 42.0.0-SNAPSHOT works for you?

Dave,

TL;DR: I suggest to review "feat: use java.util.logging", test it, merge it
and release the resulting artifact as pgjdbc 42.0.0

Are there any concerns regarding that plan?

As far as I see, 42.0.0 has already go great number of features/fixes
merged: https://github.com/pgjdbc/pgjdbc/milestone/6?closed=1

There is "just one" known issue: "wrong statement gets used when app code
uses different bind types for the same placeholder"
https://github.com/pgjdbc/pgjdbc/pull/674
I would consider it more of an application issue, as it is not that good
idea to reuse exactly the same statement with different bind types.
I did try to review and test the PR a couple of times, however I do not
feel it is ready to be merged. It is likely there exist other edge cases
that might need treatment.

There's a set of other great PRs, however I think it is better to release
42.0.0 now, and review/merge other PRs afterwards.

Vladimir

пт, 3 февр. 2017 г. в 15:00, Dave Cramer <pg(at)fastcrypt(dot)com>:

> Hi Malcolm,
>
> I've posted this as an issue https://github.com/pgjdbc/pgjdbc/issues/742
>
>
> I hope to have some time to look at this today
>
> Dave Cramer
>
> davec(at)postgresintl(dot)com
> www.postgresintl.com
>
> On 2 February 2017 at 17:22, Malcolm Studd <
> malcolm(dot)studd(at)tradingcentral(dot)com> wrote:
>
> I am running an application in wildfly 9.0.2 using postgres 9.2.19
> databases accessed through pgBouncer 1.7.2 in transaction pooling mode.
> With recent versions of postgresql-jdbc, the application is failing with
> prepared statement does not exist errors.
>
> 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.tr
> ansaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1212)
> at com.arjuna.ats.internal.jta.tr
> ansaction.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.Ba
> tchEnvironmentService$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.Sy
> nchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:119)
> at org.hibernate.engine.transaction.synchronization.internal.Re
> gisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:50)
> at
> org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.beforeCompletion(JCAOrderedLastSynchronizationList.java:116)
> at com.arjuna.ats.internal.jta.re
> sources.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.tr
> ansaction.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.Sy
> nchronizationCallbackCoordinatorNonTrackingImpl.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.Ba
> tchEnvironmentService$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
> <datasource jta="false"
> jndi-name="java:jboss/datasources/eventdb001" pool-name="eventdb001"
> use-ccm="false">
>
>
> <connection-url>jdbc:postgresql://${recognia.datasource.eventdb001.host}:${recognia.datasource.eventdb001.port}/${recognia.
> datasource.eventdb001.name.work}</connection-url>
> <driver-class>org.postgresql.Driver</driver-class>
> <connection-property name="prepareThreshold">
> 0
> </connection-property>
> <driver>postgres</driver>
>
> <transaction-isolation>TRANSACTION_READ_COMMITTED</transaction-isolation>
> <pool>
> <min-pool-size>1</min-pool-size>
> <max-pool-size>300</max-pool-size>
> <prefill>true</prefill>
>
> <flush-strategy>IdleConnections</flush-strategy>
> </pool>
> <security>
>
> <user-name>${recognia.datasource.eventdb001.user}</user-name>
>
> <password>${recognia.datasource.eventdb001.password}</password>
> </security>
> <validation>
> <valid-connection-checker
> class-name="org.jboss.jca.adapters.jdbc.extensions.postgres.PostgreSQLValidConnectionChecker"/>
> <check-valid-connection-sql>select
> 1</check-valid-connection-sql>
> <validate-on-match>true</validate-on-match>
>
> <background-validation>true</background-validation>
>
> <background-validation-millis>5000</background-validation-millis>
> <stale-connection-checker
> class-name="org.jboss.jca.adapters.jdbc.extensions.novendor.NullStaleConnectionChecker"/>
> <exception-sorter
> class-name="org.jboss.jca.adapters.jdbc.extensions.postgres.PostgreSQLExceptionSorter"/>
> </validation>
> <timeout>
> <idle-timeout-minutes>1</idle-timeout-minutes>
> </timeout>
> <statement>
> <track-statements>true</track-statements>
>
> <share-prepared-statements>false</share-prepared-statements>
> </statement>
> </datasource>
>
> --
>
>
> [image: Recognia] <http://www.recognia.com/> W www.recognia.com W
> www.tradingcentral.com [image: twitter] <https://twitter.com/Recognia>
> [image: facebook] <https://www.facebook.com/recognia/> [image: linkedin] <
> https://www.linkedin.com/company/recognia-inc->
>
> insightful analytics. expert analyst views. moving forward together.
>
> Ottawa
> 200-301 Moodie Drive
> Ottawa, ON, K2H 9C4
> T +1 613 789 2267 Hong Kong
> 60 Wyndham Street, 2003B
> Central, Hong Kong
> T +852 2522 3988 Paris
> 11 bis rue Scribe​
> 75009 Paris​
> T +33 1 5528 8040 London
> 36 Old Jewry
> London. EC2R 8DD
> T +44 203 440 7615 New York
> 60 Broad Street, Suite 3502
> New York, NY 10004
> T +1 212 847 2387
>
> *© TRADING CENTRALTM* [image: 1999-2016] The information contained in this
> email is for informational purposes only. It does not constitute advice or
> a recommendation by any of the TRADING CENTRAL group of companies,
> including Recognia Inc. ("TRADING CENTRAL") in respect of the investment in
> financial instruments. It is not intended as an offer or solicitation for
> the purchase or sale of any financial instrument. The investment in
> financial instruments is characterized by a certain degree of uncertainty.
> Any such investment involves risks for which TRADING CENTRAL is not liable.
> Any information offered herein reflects the current judgment of TRADING
> CENTRAL, which is not guaranteed, may be incomplete and may change without
> notice. Services in the U.S. are offered through TRADING CENTRAL Americas,
> Inc.. This message may contain confidential and proprietary information of
> TRADING CENTRAL and is intended only for the designated recipient(s). If
> you are not the intended recipient of this message you are hereby notified
> that any review, dissemination, distribution or copying of this message is
> strictly prohibited.
> Click here to unsubscribe <unsubscribe(at)recognia(dot)com>
>
>
> --
> Sent via pgsql-jdbc mailing list (pgsql-jdbc(at)postgresql(dot)org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-jdbc
>
>
>