Atomikos Forum

Our Sys Admins reported "lots of logging" for one of our web applications which uses Atomikos. Closer investigation taught us that the culprit is incessant logging of the line
atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool

Below is an excerpt of the hundreds of megabytes of logging:

10-05-20 08:51:05,210 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,211 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,212 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,214 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,215 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,216 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,217 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,219 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,220 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,221 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,223 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,224 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-20 08:51:05,228 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool

Any idea what is going wrong? This is for Atomikos 3.5.9.

Regards,
Rik Gruwez

Hi,

What is the value of the maintenanceInterval property of your datasource? Looks like it is very low...

HTH

Hi Guy,
There is no value set for maintenanceInterval. Below is the configuration of the datasource:

<Resource auth="Container"
 factory="com.atomikos.tomcat.BeanFactory"
 maxPoolSize="50" minPoolSize="5" name="jdbc/ASR_XA_Managed"
 type="com.atomikos.jdbc.AtomikosDataSourceBean"
 uniqueResourceName="AtomikosDataSourceJDBCOracle.ASR_WS"
 xaDataSourceClassName="oracle.jdbc.xa.client.OracleXADataSource"
 xaProperties.URL="..." xaProperties.password="..." xaProperties.user="..." testQuery="select 1 from asr_config"/>

The problem went away after we had restarted Tomcat.

Any idea?
Regards,
Rik

OK, the problem reoccurred last night, creating Gigabytes of logging containing nothing but these entries:

10-05-25 11:26:05,867 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,869 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,871 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,873 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,875 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,877 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,878 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,880 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,882 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,883 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,885 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,887 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,889 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,891 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,893 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,894 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,896 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,898 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,900 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,902 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,904 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-25 11:26:05,906 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool

As you can see, the entry reappears every two to three milliseconds. Not only does this result in an enormous amount of logging, but I suppose it also takes a big strain on the CPU.

I had a look in the Atomikos source code and, indeed, the timer used to shrink the pool is governed by the maintenanceInterval property. This is not set in our environment, so it would default to 60 seconds. The strange this is that when the server is restarted, the logs indeed indicate a one minute interval between each shrink attempt.

10-05-26 10:33:50,173 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-26 10:34:50,169 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool
10-05-26 10:35:50,164 [Atomikos:0] atomikos connection pool 'AtomikosDataSourceJDBCOracle.ASR_WS': trying to shrink pool

Then, for some odd reason, the timer goes berzerk and triggers the shrinking attempt every 2 to 3 milliseconds. The only solution is to stop and restart Tomcat.

I have tried to look into the PooledAlarmTimer class and its related classes, but at first glance I could not find anything wrong. Still, there must me something wrong somewhere.

All and any input would be tremendously appreciated.

Regards,
Rik

Are there other Atomikos users out there who are experiencing the same problem? It reoccurs in our application on a daily basis.

Rik,

I have seen this log statement in my atomikos logs. But it is not so incessant. which version of atomikos are you using? we use 3.6.2 and keep the default interval. would it help if you set the log level to WARN or disable the atomikos logging altogether?

regards
Prasad