Recently a bug was noticed in our application which caused the time of the operation to differ from the actual time(we are using current_timestamp() PostgreSQL function instead of passing time from the code). We've looked into it and discovered that the problem had to with some transaction which was starting and was never ended.
The application uses Spring's DataSourceTransactionManager which does it job perfectly (every transactional operations are being concluded as expected). Now, the problem seems to be coming from our connection pool lib(BoneCP). We have configured SELECT 1 query to check database connectivity. And what is actually shown in PostgreSQL log is the following:
LOG: execute S_1: BEGIN
LOG: execute <unnamed>: SELECT 1
LOG: execute S_1: BEGIN
LOG: execute <unnamed>: SELECT 1
No COMMIT is following any of the connection test statement (further log shows no more BEGIN commands before SELECT 1, but I guess it is because that connection cannot start new transaction while one is already active..
I am wondering if it is some bug or what might be wrong?
Here is servlet-context configuration part file(only posting relevant parts):
<bean id="ds" class="com.jolbox.bonecp.BoneCPDataSource" destroy-method="close">
<property name="idleConnectionTestPeriodInMinutes" value="5"/>
<property name="idleMaxAgeInMinutes" value="30"/>
<property name="lazyInit" value="true"/>
<property name="maxConnectionsPerPartition" value="95"/>
<property name="minConnectionsPerPartition" value="1"/>
<property name="partitionCount" value="3"/>
<property name="acquireIncrement" value="5"/>
<property name="statementsCacheSize" value="100"/>
<property name="releaseHelperThreads" value="3"/>
<property name="defaultAutoCommit" value="false"/>
<property name="connectionTestStatement" value="SELECT 1;"/>
</bean>
<bean id="sql" class="groovy.sql.Sql">
<constructor-arg ref="dsProxy"/>
</bean>
<tx:annotation-driven transaction-manager="txManager" proxy-target-class="true"/>
<bean id="dsProxy" class="org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy">
<constructor-arg ref="fooDSProxy"/>
</bean>
<bean id="fooDSProxy" class="org.something.Foo" factory-method="createProxy">
<constructor-arg ref="ds"/>
</bean>
<bean id="txManager" class="org.springframework.jdbc.datasource.DataSourceTransactionManager">
<property name="dataSource" ref="dsProxy"/>
</bean>
Where org.something.Foo has nothing special, used for logging purposes.
Any help appreciated.
The issue is likely to be due to the autocommit settings on your database connections.
As the name would imply, autocommit automatically wraps each SQL statement in its own transaction and implicitly commits that transaction when the statement has finished. For a lot of production scenarios, autocommit doesn't make sense; you typically want to group together a batch of SQL operations into a single transaction and then either commit or rollback the unit of work.
Your database connection pool settings explicitly turns off autocommit on the connections, therefore I would suggest that your SELECT 1 connection test statement is being executed in a transaction that has no explicit commit. This would explain why you see the BEGIN statement and then no commit afterwards. The way to resolve this is to update your connection test statement to include explicit transaction demarcation e.g. add a BEGIN and COMMIT to the statement.
In terms of what actually happens to those connections that are not committed, that will depend upon the actual database implementation itself. It might be worth reading up on what PostgreSQL will do here.
The Hibernate documentation provides a pretty good explanation of what happens relying upon autocommit. Definitely worth a read.