On May 27, 2013, at 7:40 AM, Huub Sepers <h.sep...@portbase.com> wrote:
> Hi, > > > > We are experiencing some problems while using the tomcat jdbc pool. > > > > Tomcat version: apache-tomcat-7.0.29 Try the latest version. Your's is pretty old. > > Pool settings: > > <Resource name="PilDevDS" auth="Container" type="javax.sql.DataSource" > factory="org.apache.tomcat.jdbc.pool.DataSourceFactory" > > testWhileIdle="true" testOnBorrow="true" > testOnReturn="false" validationQuery="SELECT 1 FROM PIL_USERS" > > validationInterval="30000" > timeBetweenEvictionRunsMillis="30000" maxActive="100" minIdle="10" > maxWait="10000" > > initialSize="10" removeAbandonedTimeout="60" > removeAbandoned="true" logAbandoned="true" > minEvictableIdleTimeMillis="30000" > > jmxEnabled="true" > > > jdbcInterceptors="org.apache.tomcat.jdbc.pool.interceptor.ConnectionStat > e;org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer" > > username="PCS" password="xxx" > driverClassName="oracle.jdbc.driver.OracleDriver" > url="jdbc:oracle:thin:@somehost" /> Looks OK. > Under heavy load we regularly see a thread waiting for response on a > "socketRead". > > Furthermore we see one or more threads trying to lock the same physical > connection as used by the 'hanging thread'. > > See threaddump excerpt further on for an example. > > Questions: > > - How is it possible that a thread tries to get a lock on a > physical connection which is part of a pooled connection which is not > idle? > > - The 'poolcleaner' also hangs as it is trying to clean the > 'hanging connection'. This would mean that one hanging thread will bring > the pool to its knees? I don't think the threads are doing quite what you think they are doing. See below. > > Threaddump excerpt: > > "http-bio-8280-exec-148" - Thread t@265 > > java.lang.Thread.State: RUNNABLE > > at java.net.SocketInputStream.socketRead0(Native Method) This is reading from the network. Hard to say why exactly. Is your network slow? How much data are you pulling back through the connection? > at java.net.SocketInputStream.read(SocketInputStream.java:129) > at oracle.net.ns.Packet.receive(Packet.java:300) > at oracle.net.ns.DataPacket.receive(DataPacket.java:106) > at > oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315) > at oracle.net.ns.NetInputStream.read(NetInputStream.java:260) > at oracle.net.ns.NetInputStream.read(NetInputStream.java:185) > at oracle.net.ns.NetInputStream.read(NetInputStream.java:102) > at > oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketI > nputStreamWrapper.java:124) > at > oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStream > Wrapper.java:80) > at > oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137) > at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290) > at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192) > at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:531) > at > oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.jav > a:207) > at > oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatem > ent.java:1044) > at > oracle.jdbc.driver.OraclePreparedStatement.executeForRowsWithTimeout(Ora > clePreparedStatement.java:10143) > at > oracle.jdbc.driver.OraclePreparedStatement.executeBatch(OraclePreparedSt > atement.java:10249) > > - locked <14d02b3> (a oracle.jdbc.driver.T4CConnection) This is occurring in the Oracle driver, not the connection pool. Sorry, I can't really comment as to why it's locking here as I don't have the code. > at > oracle.jdbc.driver.OracleStatementWrapper.executeBatch(OracleStatementWrapper.java:230) <snip> The rest of this stack trace doesn't seem to reference the connection pool. I don't see "org.apache.tomcat.jdbc.*" listed anywhere. How is your application configured to get a connection from the connection pool? Is it possible that it's getting the connection some other way, not properly closing / returning the connection to the pool or unwrapping and accessing the underlying connection? > > "http-bio-8280-exec-206" - Thread t@324 > > java.lang.Thread.State: BLOCKED > > at > oracle.jdbc.driver.PhysicalConnection.prepareStatement(PhysicalConnectio > n.java:3461) > - waiting to lock <14d02b3> (a oracle.jdbc.driver.T4CConnection) > owned by "http-bio-8280-exec-148" t@265 Again, this is blocking in the driver. > at sun.reflect.GeneratedMethodAccessor28.invoke(Unknown Source) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at > org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(ProxyConnection.java:126) > at > org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:99) > at > org.apache.tomcat.jdbc.pool.interceptor.AbstractCreateStatementInterceptor.invoke(AbstractCreateStatementInterceptor.java:67) > at > org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:99) > at > org.apache.tomcat.jdbc.pool.interceptor.ConnectionState.invoke(ConnectionState.java:153) > This is what I would have expected to see in the thread "http-bio-8280-exec-148", but didn't. This is indicating that the connection was obtained through the connection pool, you can tell because the connection is wrapped by interceptors. > "PoolCleaner[28290629:1368625550375]" - Thread t@19 > > java.lang.Thread.State: BLOCKED > > at > oracle.jdbc.driver.PhysicalConnection.close(PhysicalConnection.java:3957) > - waiting to lock <18ed651> (a oracle.jdbc.driver.T4CConnection) > owned by "http-bio-8280-exec-83" t@179 The pool cleaner thread called close on a thread, that triggered the driver to block for some reason. It's blocking on "http-bio-8280-exec-83", but I don't see that thread here, so it's hard to say what it's doing. > at > org.apache.tomcat.jdbc.pool.PooledConnection.disconnect(PooledConnection.java:330) > at > org.apache.tomcat.jdbc.pool.PooledConnection.release(PooledConnection.java:489) > at > org.apache.tomcat.jdbc.pool.ConnectionPool.release(ConnectionPool.java:578) > at > org.apache.tomcat.jdbc.pool.ConnectionPool.abandon(ConnectionPool.java:537) > at > org.apache.tomcat.jdbc.pool.ConnectionPool.checkAbandoned(ConnectionPool.java:955) Look at the rest of the stack trace. You can see that the pool cleaner thread is checking for abandoned threads. It's trying to release your thread because it thinks that it's abandoned. You have "removeAbandonedTimeout" set to "60", so that means your application is holding the thread for more than 60 seconds. You'll want to check further to see why your application is holding it for so long. If it's legit, you might want to add the "ResetAbandonedTimer" interceptor. That will reset the clock on the abandoned timeout every time the connection executes an SQL statement, rather than when it's checked out of the pool. https://tomcat.apache.org/tomcat-7.0-doc/jdbc-pool.html#org.apache.tomcat.jdbc.pool.interceptor.ResetAbandonedTimer Dan --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
