Skip to content

Instantly share code, notes, and snippets.

@ecki ecki/AbandonTest.java
Last active Aug 29, 2015

Embed
What would you like to do?
commons-dbcp abandon connection killing
package net.eckenfels.test.dbcp;
import java.io.PrintWriter;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.SQLException;
import java.util.Locale;
import java.util.TimeZone;
import javax.management.ObjectName;
import javax.sql.DataSource;
import oracle.jdbc.pool.OracleDataSource;
import org.apache.commons.dbcp2.ConnectionFactory;
import org.apache.commons.dbcp2.DataSourceConnectionFactory;
import org.apache.commons.dbcp2.PoolableConnection;
import org.apache.commons.dbcp2.PoolableConnectionFactory;
import org.apache.commons.dbcp2.PoolingDataSource;
import org.apache.commons.dbcp2.SwallowedExceptionLogger;
import org.apache.commons.logging.LogFactory;
import org.apache.commons.logging.impl.SimpleLog;
import org.apache.commons.pool2.impl.AbandonedConfig;
import org.apache.commons.pool2.impl.GenericObjectPool;
public class AbandonTest
{
public final static int TIMEOUT = 4; // c3 is 10s idle
@SuppressWarnings("resource")
public static void main(String[] args) throws SQLException, InterruptedException
{
LogFactory.getFactory().setAttribute("org.apache.commons.logging.Log", SimpleLog.class.getName());
LogFactory.getFactory().setAttribute("org.apache.commons.logging.simplelog.defaultlog", "TRACE");
// works: LogFactory.getLog(AbandonTest.class).debug("Try debug");
if (args.length < 2 ||args.length > 3)
{
throw new IllegalArgumentException("java " + AbandonTest.class.getName() + " <user> <pass> [<url>]");
}
System.out.printf("Ora Close Test jre=%s loc=%s tz=%s os=%s/%s%n", System.getProperty("java.version"), Locale.getDefault().toString(), TimeZone.getDefault().getID(), System.getProperty("os.name", "N/A"), System.getProperty("os.version"));
// extract options and arguments
String url;
if (args.length > 2)
{
url = args[2];
}
else
{
url = "jdbc:oracle:thin:@eckenfelsb01:1521:eckenfels01";
}
OracleDataSource ods = new OracleDataSource();
ods.setURL(url);
ods.setUser(args[0]);
ods.setPassword(args[1]);
DataSource ds = setupDS(ods);
System.out.println("1 - get");
final Connection c1 = ds.getConnection();
System.out.println("1 - got");
System.out.println(" Driver=" + c1.getMetaData().getDriverVersion() + " timeout=" + TIMEOUT + "s");
new Thread() {
@Override
public void run()
{
System.out.println("1 - create");
try {
PreparedStatement s = c1.prepareStatement("BEGIN DBMS_LOCK.sleep(20); END;");
System.out.println("1 - exec");
s.execute();
System.out.println("1 - close");
s.close(); c1.close();
System.out.println("1 - done");
} catch (Exception e) {
System.out.println("1 - "); e.printStackTrace();
}
}
}.start();
Thread.sleep(6*1000);
System.out.println("thread state after 6s");
dumpThreads();
System.out.println("2 - get");
final Connection c2 = ds.getConnection();
System.out.println("2 - got");
new Thread() {
@Override
public void run()
{
System.out.println("2 - create");
try {
PreparedStatement s = c2.prepareStatement("BEGIN DBMS_LOCK.sleep(20); END;");
System.out.println("2 - exec");
s.execute();
System.out.println("2 - close");
s.close(); c2.close();
System.out.println("2 - done");
} catch (Exception e) {
System.out.print("2 - "); e.printStackTrace();
}
}
}.start();
System.out.println("3 - get");
final Connection c3 = ds.getConnection();
System.out.println("3 - got");
Thread.sleep(10 * 1000);
System.out.println("3 - slept");
new Thread() {
@Override
public void run()
{
System.out.println("3 - create");
try {
PreparedStatement s = c3.prepareStatement("BEGIN DBMS_LOCK.sleep(20); END;");
System.out.println("3 - exec");
s.execute();
System.out.println("3 - close");
s.close(); c3.close();
System.out.println("3 - done");
} catch (Exception e) {
System.out.print("3 - "); e.printStackTrace();
}
}
}.start();
Thread.sleep(3 * 1000);
dumpThreads();
}
/**
*
*/
private static void dumpThreads()
{
ThreadInfo[] dump = ManagementFactory.getThreadMXBean().dumpAllThreads(true, true);
for(int i=0;i<dump.length;i++)
System.out.println(dump[i]);
}
static DataSource setupDS(DataSource ods)
{
SwallowedExceptionLogger log = new SwallowedExceptionLogger(LogFactory.getLog("dbcp"), true);
PrintWriter printer = new PrintWriter(System.out, true);
ConnectionFactory cf = new DataSourceConnectionFactory(ods);
PoolableConnectionFactory pcf = new PoolableConnectionFactory(cf, (ObjectName)null);
GenericObjectPool<PoolableConnection> pool = new GenericObjectPool<>(pcf);
pcf.setPool(pool);
AbandonedConfig acfg = new AbandonedConfig();
acfg.setLogAbandoned(true);
acfg.setRemoveAbandonedOnMaintenance(true);
acfg.setRemoveAbandonedOnBorrow(true);
acfg.setRemoveAbandonedTimeout(TIMEOUT);
acfg.setUseUsageTracking(true);
acfg.setLogWriter(printer);
pool.setAbandonedConfig(acfg);
pool.setMaxTotal(2);
pool.setMinIdle(1);
pool.setTimeBetweenEvictionRunsMillis(1000);
pool.setSwallowedExceptionListener(log);
LogFactory.getLog("setupDS").debug("pool.getLogAbandoned()=" + pool.getLogAbandoned());
PoolingDataSource<PoolableConnection> pds = new PoolingDataSource<>(pool);
pds.setLogWriter(printer);
return pds;
}
}
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<groupId>net.eckenfels.test</groupId>
<artifactId>dbcp-test</artifactId>
<version>0.0.1-SNAPSHOT</version>
<properties>
<maven.compiler.source>1.7</maven.compiler.source>
<maven.compiler.target>1.7</maven.compiler.target>
</properties>
<dependencies>
<dependency>
<groupId>org.apache.commons</groupId>
<artifactId>commons-pool2</artifactId>
<version>2.3</version>
</dependency>
<dependency>
<groupId>org.apache.commons</groupId>
<artifactId>commons-dbcp2</artifactId>
<version>2.1</version>
</dependency>
<dependency>
<groupId>commons-logging</groupId>
<artifactId>commons-logging</artifactId>
<version>1.2</version>
</dependency>
<dependency>
<groupId>com.oracle</groupId>
<artifactId>ojdbc6</artifactId>
<version>12.1.0.1.0</version>
<scope>provided</scope>
</dependency>
</dependencies>
</project>
Ora Close Test jre=1.8.0_40 loc=de_DE tz=Europe/Berlin os=Windows 7/6.1
1 - get
1 - got
Driver=12.1.0.1.0 timeout=12s
1 - create
1 - exec
thread state after 6s
"Thread-2" Id=14 RUNNABLE (in native)
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at oracle.net.ns.Packet.receive(Packet.java:311)
at oracle.net.ns.DataPacket.receive(DataPacket.java:105)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:305)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:249)
...
"commons-pool-EvictionTimer" Id=12 TIMED_WAITING on java.util.TaskQueue@366e2eef
at java.lang.Object.wait(Native Method)
- waiting on java.util.TaskQueue@366e2eef
at java.util.TimerThread.mainLoop(Timer.java:552)
at java.util.TimerThread.run(Timer.java:505)
"main" Id=1 RUNNABLE
at sun.management.ThreadImpl.dumpThreads0(Native Method)
at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:446)
at net.eckenfels.test.dbcp.AbandonTest.dumpThreads(AbandonTest.java:152)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:98)
2 - get
2 - got
3 - get
2 - create
2 - exec
org.apache.commons.pool2.impl.DefaultPooledObject$AbandonedObjectCreatedException: Pooled object created 2015-07-27 22:36:20 +0200 by the following code has not been returned to the pool:
at org.apache.commons.pool2.impl.DefaultPooledObject.allocate(DefaultPooledObject.java:198)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:452)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:363)
at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:75)
1 - close
1 - done
3 - got
org.apache.commons.pool2.impl.DefaultPooledObject$AbandonedObjectCreatedException: Pooled object created 2015-07-27 22:36:26 +0200 by the following code has not been returned to the pool:
at org.apache.commons.pool2.impl.DefaultPooledObject.allocate(DefaultPooledObject.java:198)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:452)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:363)
at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:101)
2 - close
2 - done
3 - slept
3 - create
3 - exec
"Thread-4" Id=16 RUNNABLE (in native)
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at oracle.net.ns.Packet.receive(Packet.java:311)
at oracle.net.ns.DataPacket.receive(DataPacket.java:105)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:305)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:249)
...
"commons-pool-EvictionTimer" Id=12 TIMED_WAITING on java.util.TaskQueue@366e2eef
at java.lang.Object.wait(Native Method)
- waiting on java.util.TaskQueue@366e2eef
at java.util.TimerThread.mainLoop(Timer.java:552)
at java.util.TimerThread.run(Timer.java:505)
"main" Id=1 RUNNABLE
at sun.management.ThreadImpl.dumpThreads0(Native Method)
at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:446)
at net.eckenfels.test.dbcp.AbandonTest.dumpThreads(AbandonTest.java:152)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:144)
org.apache.commons.pool2.impl.DefaultPooledObject$AbandonedObjectCreatedException: Pooled object created 2015-07-27 22:36:40 +0200 by the following code has not been returned to the pool:
at org.apache.commons.pool2.impl.DefaultPooledObject.allocate(DefaultPooledObject.java:198)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:452)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:363)
at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:121)
3 - close
3 - done
Ora Close Test jre=1.8.0_40 loc=de_DE tz=Europe/Berlin os=Windows 7/6.1
1 - get
1 - got
Driver=12.1.0.1.0 timeout=4s
1 - create
1 - exec
org.apache.commons.pool2.impl.DefaultPooledObject$AbandonedObjectCreatedException: Pooled object created 2015-07-27 22:33:59 +0200 by the following code has not been returned to the pool:
at org.apache.commons.pool2.impl.DefaultPooledObject.allocate(DefaultPooledObject.java:198)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:452)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:363)
at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:75)
thread state after 6s
"Thread-2" Id=14 RUNNABLE (in native)
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at oracle.net.ns.Packet.receive(Packet.java:311)
at oracle.net.ns.DataPacket.receive(DataPacket.java:105)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:305)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:249)
...
"commons-pool-EvictionTimer" Id=12 BLOCKED on oracle.jdbc.driver.T4CConnection@3cd1f1c8 owned by "Thread-2" Id=14
at oracle.jdbc.driver.OracleStatement.close(OracleStatement.java:1343)
- blocked on oracle.jdbc.driver.T4CConnection@3cd1f1c8
at oracle.jdbc.driver.OracleStatementWrapper.close(OracleStatementWrapper.java:100)
at oracle.jdbc.driver.OraclePreparedStatementWrapper.close(OraclePreparedStatementWrapper.java:82)
at org.apache.commons.dbcp2.DelegatingStatement.close(DelegatingStatement.java:156)
at org.apache.commons.dbcp2.DelegatingConnection.passivate(DelegatingConnection.java:631)
at org.apache.commons.dbcp2.PoolableConnection.passivate(PoolableConnection.java:127)
at org.apache.commons.dbcp2.DelegatingConnection.closeInternal(DelegatingConnection.java:232)
at org.apache.commons.dbcp2.PoolableConnection.reallyClose(PoolableConnection.java:243)
...
"main" Id=1 RUNNABLE
at sun.management.ThreadImpl.dumpThreads0(Native Method)
at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:446)
at net.eckenfels.test.dbcp.AbandonTest.dumpThreads(AbandonTest.java:152)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:98)
2 - get
2 - got
3 - get
2 - create
2 - exec
1 - close
1 - done
3 - got
org.apache.commons.pool2.impl.DefaultPooledObject$AbandonedObjectCreatedException: Pooled object created 2015-07-27 22:34:05 +0200 by the following code has not been returned to the pool:
at org.apache.commons.pool2.impl.DefaultPooledObject.allocate(DefaultPooledObject.java:198)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:452)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:363)
at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:101)
2 - close
2 - done
org.apache.commons.pool2.impl.DefaultPooledObject$AbandonedObjectCreatedException: Pooled object created 2015-07-27 22:34:19 +0200 by the following code has not been returned to the pool:
at org.apache.commons.pool2.impl.DefaultPooledObject.allocate(DefaultPooledObject.java:198)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:452)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:363)
at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:121)
3 - slept
3 - create
3 - java.sql.SQLException: Connection oracle.jdbc.driver.T4CConnection@34edac28 is closed.
at org.apache.commons.dbcp2.DelegatingConnection.checkOpen(DelegatingConnection.java:605)
at org.apache.commons.dbcp2.DelegatingConnection.prepareStatement(DelegatingConnection.java:286)
at org.apache.commons.dbcp2.DelegatingConnection.prepareStatement(DelegatingConnection.java:288)
at net.eckenfels.test.dbcp.AbandonTest$3.run(AbandonTest.java:131)
"commons-pool-EvictionTimer" Id=12 TIMED_WAITING on java.util.TaskQueue@35fb3008
at java.lang.Object.wait(Native Method)
- waiting on java.util.TaskQueue@35fb3008
at java.util.TimerThread.mainLoop(Timer.java:552)
at java.util.TimerThread.run(Timer.java:505)
"main" Id=1 RUNNABLE
at sun.management.ThreadImpl.dumpThreads0(Native Method)
at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:446)
at net.eckenfels.test.dbcp.AbandonTest.dumpThreads(AbandonTest.java:152)
at net.eckenfels.test.dbcp.AbandonTest.main(AbandonTest.java:144)
@ecki

This comment has been minimized.

Copy link
Owner Author

ecki commented Jul 27, 2015

Logging requires autoflush till POOL-300 is fixed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.