Sunday, November 23, 2008

MySQL connection problem with “Spring Transaction Management”

This problem bugs me for a long long time.. it happens when need DB access after a certain period of inactivity. It gives you like:

org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Connection.close() has already been called. Invalid operation in this state.
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:583)
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:501)
javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
javax.servlet.http.HttpServlet.service(HttpServlet.java:803)

root cause

org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Connection.close() has already been called. Invalid operation in this state.
org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:238)
org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:377)
org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:263)
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:101)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
$Proxy15.searchMovies(Unknown Source)
com.showman.mediaapp.web.MainViewController.handleRequest(MainViewController.java:36)
org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:571)
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:501)
javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
javax.servlet.http.HttpServlet.service(HttpServlet.java:803)

root cause

com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Connection.close() has already been called. Invalid operation in this state.
sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
java.lang.reflect.Constructor.newInstance(Unknown Source)
com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
com.mysql.jdbc.Util.getInstance(Util.java:381)
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984)
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3018)
com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:4827)
org.apache.commons.dbcp.DelegatingConnection.setAutoCommit(DelegatingConnection.java:331)
org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.setAutoCommit(PoolingDataSource.java:317)
org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:221)
org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:377)
org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:263)
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:101)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
$Proxy15.searchMovies(Unknown Source)
com.showman.mediaapp.web.MainViewController.handleRequest(MainViewController.java:36)
org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:571)
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:501)
javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
javax.servlet.http.HttpServlet.service(HttpServlet.java:803)

After done some research, I found out this problem could be a stale DB connection problem (connection killed by the DB server , but still considered alive by the connection pool). I am using MySQL and DBCP from Apaches Commons, now I set pool maxWait (for connection return to pool) from indefinitely to 3000 milliseconds and see if the problem can be solved...

No comments: