We are using Java with Spring to access AS/400 databases via Ibatis and
the SQLMapClient, and pooling connections via the Apache Commons DBCP.
We have a problem when the application remains running, but the AS/400
connection is lost, due to a closed job or an IPL or whatever. After
this happens, the first call on the database fails, though subsequent
calls succeed.
The odd thing is that it seems to be failing while trying to return the
bad connection, presumably as part of some cleanup operation, which
would hopefully be followed by an attempt to reconnect? It looks to me
as though the Spring DataSourceUtils finds that the connection is dead,
and tries to return it to the pool (presumably prior to obtaining a less
dead one?) and clashes with the Tomcat DBCP that has already done so.
But I cannot seem to find a way of seeing what is going on during this
process, as I can't find out how to log these actions in any more
detail.
So I don't know how to correct this issue... can anyone help me?
We are setting up an Ibatis DataSource in Spring like this :
[CODE]<bean id="iseriesJdbcDataSource"
class="org.springframework.jndi.JndiObjectFactoryBean">
<property name="jndiName">
<value>java:comp/env/jdbc/host</value>
</property>
</bean>
<bean id="sqlMapClient"
class="org.springframework.orm.ibatis.SqlMapClientFactoryBean">
<property name="configLocation">
<value>/WEB-INF/sql-map-config.xml</value>
</property>
<property name="useTransactionAwareDataSource">
<value>true</value>
</property>
<property name="dataSource">
<ref bean="iseriesJdbcDataSource"/>
</property>
</bean>
<bean id="sqlMapClientTemplate"
class="org.springframework.orm.ibatis.SqlMapClientTemplate">
<property name="sqlMapClient">
<ref bean="sqlMapClient"/>
</property>
</bean>
<bean id="ourDAO" class="uk.co.XXX.our.dao.OurIbatisDAO">
<property name="sqlMapClientTemplate">
<ref bean="sqlMapClientTemplate"/>
</property>
</bean>[/CODE]
Which uses the following settings in the Ibatis sql-map-client.xml :
[CODE] <transactionManager type="JDBC">
<dataSource type="JNDI">
<property name="DataSource" value="java:comp/env/jdbc/host" />
</dataSource>
</transactionManager>[/CODE]
And also these Apache DBCP settings in context.xml :
[CODE]<Resource name="jdbc/host"
auth="Container"
type="javax.sql.DataSource"
driverClassName="com.ibm.as400.access.AS400JDBCDriver"
url="jdbc:as400://999.999.999.999/HOSTLIB;prompt=false;naming=system;dat
eformat=iso"
username="HOSTUSER"
password="HOSTPWD" />
<ResourceParams name="jdbc/host">
<parameter>
<name>factory</name>
<value>org.apache.commons.dbcp.BasicDataSourceFactory</value>
</parameter>
<parameter>
<name>maxActive</name>
<value>10</value>
</parameter>
<parameter>
<name>maxIdle</name>
<value>2</value>
</parameter>
<parameter>
<name>maxWait</name>
<value>100</value>
</parameter>
<parameter>
<name>testOnBorrow</name>
<value>true</value>
</parameter>
<parameter>
<name>validationQuery</name>
<value>select 1</value>
</parameter>
</ResourceParams>[/CODE]
Using these log4J settings to get the debugs :
[CODE]log4j.category.com.ibatis = DEBUG, file
log4j.category.org.apache = DEBUG, file
log4j.category.org.springframework = DEBUG, file[/CODE]
We see logging like this for a successful result, AS/400 present, all is
well :
[CODE]11:43:45,271 uk.co.XXX.our.soap.OurService.getItem():359 - Using
sqlMapClient >[EMAIL PROTECTED]<
11:43:45,271 uk.co.XXX.our.soap.OurService.getItem():361 -
sqlMapClient.getCurrentConnection() is >null<
11:43:45,271 uk.co.XXX.our.soap.OurService.getItem():363 -
sqlMapClient.getDataSource() is
>[EMAIL PROTECTED]
9efc<
11:43:45,287
org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection():11
1 - Fetching JDBC Connection from DataSource
11:43:52,803
com.ibatis.common.logging.jakarta.JakartaCommonsLoggingImpl.debug():23 -
{conn-100000} Connection
11:43:53,365
com.ibatis.common.logging.jakarta.JakartaCommonsLoggingImpl.debug():23 -
{pstm-100001} PreparedStatement: select count(*) from etc, etc, etc....
11:43:53,365
com.ibatis.common.logging.jakarta.JakartaCommonsLoggingImpl.debug():23 -
{pstm-100001} Parameters: [etc, etc]
11:43:53,365
com.ibatis.common.logging.jakarta.JakartaCommonsLoggingImpl.debug():23 -
{pstm-100001} Types: [etc, etc]
11:43:54,850
com.ibatis.common.logging.jakarta.JakartaCommonsLoggingImpl.debug():23 -
{rset-100002} ResultSet
11:43:54,881
com.ibatis.common.logging.jakarta.JakartaCommonsLoggingImpl.debug():23 -
{rset-100002} Header: [00001]
11:43:54,881
com.ibatis.common.logging.jakarta.JakartaCommonsLoggingImpl.debug():23 -
{rset-100002} Result: [1]
11:43:54,975
org.springframework.jdbc.datasource.DataSourceUtils.doReleaseConnection(
):285 - Returning JDBC Connection to DataSource
[/CODE]
And logging like this for an unsuccessful result, when the AS/400 job
has been closed in the meantime :
[CODE]11:51:05,537 uk.co.XXX.our.soap.OurService.getItem():359 - Using
sqlMapClient >[EMAIL PROTECTED]<
11:51:05,537 uk.co.XXX.our.soap.OurService.getItem():361 -
sqlMapClient.getCurrentConnection() is >null<
11:51:05,537 uk.co.XXX.our.soap.OurService.getItem():363 -
sqlMapClient.getDataSource() is
>[EMAIL PROTECTED]
9efc<
11:51:05,537
org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection():11
1 - Fetching JDBC Connection from DataSource
11:51:05,537
com.ibatis.common.logging.jakarta.JakartaCommonsLoggingImpl.debug():23 -
{conn-100064} Connection
11:51:05,553
org.springframework.jdbc.datasource.DataSourceUtils.doReleaseConnection(
):285 - Returning JDBC Connection to DataSource
11:51:05,615 uk.co.XXX.our.dao.OurIbatisDAO.isItemExtant():538 - Ibatis
DAO Exception
java.sql.SQLException: Already closed.
at
org.apache.tomcat.dbcp.dbcp.PoolableConnection.close(PoolableConnection.
java:77)
at
org.apache.tomcat.dbcp.dbcp.PoolingDataSource$PoolGuardConnectionWrapper
.close(PoolingDataSource.java:180)
at
org.springframework.jdbc.datasource.DataSourceUtils.doReleaseConnection(
DataSourceUtils.java:286)
at
org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$Tran
sactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.jav
a:161)
at $Proxy52.close(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
com.ibatis.common.jdbc.logging.ConnectionLogProxy.invoke(ConnectionLogPr
oxy.java:62)
at $Proxy50.close(Unknown Source)
at
com.ibatis.sqlmap.engine.transaction.external.ExternalTransaction.close(
ExternalTransaction.java:82)
at
com.ibatis.sqlmap.engine.transaction.TransactionManager.end(TransactionM
anager.java:110)
at
com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.endTransaction(SqlM
apExecutorDelegate.java:776)
at
com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.endTransaction(SqlMapSes
sionImpl.java:137)
at
com.ibatis.sqlmap.engine.impl.SqlMapClientImpl.endTransaction(SqlMapClie
ntImpl.java:115)
at
com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.autoEndTransaction(
SqlMapExecutorDelegate.java:860)
at
com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlM
apExecutorDelegate.java:568)
at
com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlM
apExecutorDelegate.java:536)
at
com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.queryForObject(SqlMapSes
sionImpl.java:93)
at
com.ibatis.sqlmap.engine.impl.SqlMapClientImpl.queryForObject(SqlMapClie
ntImpl.java:70)
at uk.co.XXX.our.dao.OurIbatisDAO.isItemExtant(ItemIbatisDAO.java:528)
at uk.co.XXX.our.soap.OurService.getItem(OurService.java:367)
at uk.co.XXX.our.soap.OurService.getItem(OurService.java:261)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java
:397)
at etc, etc, etc....
at java.lang.Thread.run(Unknown Source)[/CODE]Cheers Tracey Annison ---------------------------------------------------------------------- The information in this email is confidential and may be legally privileged. It is intended solely for the addressee. Access to this email by anyone else is unauthorised. If you are not the intended recipient, any disclosure, copying, distribution, or any action taken or omitted to be taken in reliance on it, is prohibited and may be unlawful. TriSystems Ltd. cannot accept liability for statements made which are clearly the sender's own.
