Here is the environment:
- Java 5
- Web application running in Tomcat 6.0.18 on Windows (not sure the version)
- Database: SQL Server 2008 R2
- JDBC Driver: jTDS 1.2.5
- Connection pool provider: C3P0 0.9.1.2
I am trying to debug a problem that a client is having. Basically every couple weeks, our web application locks up on their server, and they can't access it. A restart fixes the issue. Further investigation shows that the reason everything is locked up is that everything is waiting on the database connections to return. I think the issue is likely with SQL Server, not C3P0.
What I believe is going on is that C3P0's "idle check query" is hanging. The query is this:
select * from c3p0_connection_test_table
It looks like this query is run, and the result is never returned. Here is what I see in my thread dump. Notice DefaultConnectionTester.activeCheckConnection(), which is the idle check:
"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2" daemon prio=6 tid=0x0000000007c32000 nid=0x1250 runnable [0x000000001072f000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.DataInputStream.readFully(DataInputStream.java:178)
at java.io.DataInputStream.readFully(DataInputStream.java:152)
at net.sourceforge.jtds.jdbc.SharedSocket.readPacket(SharedSocket.java:841)
at net.sourceforge.jtds.jdbc.SharedSocket.getNetPacket(SharedSocket.java:722)
- locked <0x000000016ac03f48> (a java.util.ArrayList)
at net.sourceforge.jtds.jdbc.ResponseStream.getPacket(ResponseStream.java:466)
at net.sourceforge.jtds.jdbc.ResponseStream.read(ResponseStream.java:103)
at net.sourceforge.jtds.jdbc.ResponseStream.peek(ResponseStream.java:88)
at net.sourceforge.jtds.jdbc.TdsCore.wait(TdsCore.java:3928)
at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1045)
- locked <0x000000016d965268> (a net.sourceforge.jtds.jdbc.TdsCore)
at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQLQuery(JtdsStatement.java:465)
at net.sourceforge.jtds.jdbc.JtdsStatement.executeQuery(JtdsStatement.java:1301)
at com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnection(DefaultConnectionTester.java:73)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.testPooledConnection(C3P0PooledConnectionPool.java:374)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.refurbishIdleResource(C3P0PooledConnectionPool.java:310)
at com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask.run(BasicResourcePool.java:1999)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
But what could cause such a simple query to hang at reading from the socket? I don't believe there would be any database locking on this table, as it is completely managed by C3P0 and never inserted/updated. Also, any failed attempts to get connections from the pool (if this were the cause of the hanging), I would expect a stacktrace somewhere. Instead what I see is the app just locking up, because all future connection requests are waiting for this "idle check" to complete.
Here is one of the threads that is waiting for the "idle check" to complete:
"http-80-3" daemon prio=6 tid=0x0000000007c33800 nid=0x122c in Object.wait() [0x000000001082d000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:579)
- locked <0x0000000167a88a60> (a com.mchange.v2.resourcepool.BasicResourcePool)
at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1354)
at org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:555)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:371)
at sun.reflect.GeneratedMethodAccessor105.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy15.getTransaction(Unknown Source)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:317)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:105)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy79.getCrowdProperties(Unknown Source)
at com.jamasoftware.contour.gateway.crowd.CrowdSsoServices.autoLogin(Unknown Source)
at com.jamasoftware.contour.security.AutoLoginServicesManager.autoLogin(Unknown Source)
at org.springframework.security.ui.rememberme.RememberMeProcessingFilter.doFilterHttp(RememberMeProcessingFilter.java:74)
at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
at org.springframework.security.ui.AbstractProcessingFilter.doFilterHttp(AbstractProcessingFilter.java:277)
at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
at com.jamasoftware.contour.view.filter.CheckSetupFilter.doFilter(Unknown Source)
at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
at org.springframework.security.context.HttpSessionContextIntegrationFilter.doFilterHttp(HttpSessionContextIntegrationFilter.java:235)
at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
at org.springframework.security.concurrent.ConcurrentSessionFilter.doFilterHttp(ConcurrentSessionFilter.java:99)
at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
at com.jamasoftware.contour.view.filter.ExpirationFilter.doFilter(Unknown Source)
at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
at com.jamasoftware.contour.view.filter.GzipFilter.doFilter(Unknown Source)
at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
at org.springframework.security.util.FilterChainProxy.doFilter(FilterChainProxy.java:175)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:864)
at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:579)
at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1665)
at java.lang.Thread.run(Thread.java:619)
From looking at C3P0's source code, the two lines at the top:
at java.lang.Object.wait(Native Method)
at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:579)
... only happen when the connection is waiting for the "idle check".
Unfortunately, this is a client, and I can't report the exact details of the environment here. But any suggestions I can take to them on our next call.
UPDATE:
Their application was locked up again today. Here are the things that we've tried so far:
- They have updated to the latest jTDS driver (1.2.5)
- I have set the
socketTimeoutproperty on the connection string to 300 but still the driver stays stuck on socketRead0() long after 5 minutes - We changed the active check query from "select * from c3p0_connection_test_table" to "select 1"
- We have added the
unreturnedConnectionTimeoutanddebugUnreturnedConnectionStackTracesproperties to C3P0 (these aren't catching broken connections, though)
Here are all the C3P0 connection properties we have set:
<property name="minPoolSize" value="1"/>
<property name="maxPoolSize" value="30"/>
<property name="acquireIncrement" value="3"/>
<property name="automaticTestTable" value="c3p0_connection_test_table"/>
<property name="idleConnectionTestPeriod" value="30"/>
<property name="testConnectionOnCheckin" value="true"/>
<property name="testConnectionOnCheckout" value="true"/>
One weird thing that happened was that while the application was locked up, we tried to log into SQL Server Management Studio with the application user, and it wouldn't let us in (I think it was just a normal timeout error). The database was started and listening on port 1433 (verified with telnet), so I think that means that the maximum number of connections to the database had been reached. I'm not sure if that helps determine the cause of this issue, though.
Leads followed without success:
- This person had an issue with operating systems, and potentially the number of NIC cards on the server
- An answerer below pointed me to a bug in an older version of jTDS here
Helpful answers can either ask me to check on something on the client's machine, or point me to a possible root cause. Whatever answers helps me track this down will get the bounty.
{var%20f='http://v.t.sina.com.cn/share/share.php?appkey=1515056452',u=z||d.location,p=['&url=',e(u),'&title=',e(t||d.title),'&source=',e(r),'&sourceUrl=',e(l),'&content=',c||'gb2312','&pic=',e(p||'')].join('');function%20a(){if(!window.open([f,p].join(''),'mb',['toolbar=0,status=0,resizable=1,width=440,height=430,left=',(s.width-440)/2,',top=',(s.height-430)/2].join('')))u.href=[f,p].join('');};if(/Firefox/.test(navigator.userAgent))setTimeout(a,0);else%20a();})(screen,document,encodeURIComponent,'','','https://img.manongdao.com/sparkler-677774__340.jpg', '推荐 老娘就宠你 的文章《jTDS socket hanging with C3P0 connection check (SQ》','https://www.manongdao.com/article-634872.html','页面编码gb2312|utf-8默认gb2312'));){kind=link}