[c3p0] problems closing connections/acquiring new

mcueh · **Joined:** Wed May 05, 2004 3:26 am **Posts:** 25

Hibernate version:
3.0.5
Code between sessionFactory.openSession() and session.close():

Code:

       this.session.setFlushMode(FlushMode.NEVER);
       this.transaction = session.beginTransaction();

//all database queries go in between


       try {
           transaction.commit();
       }
       catch(HibernateException e)
       {
           logger.warn("commit failed, rolling back", e);
           transaction.rollback();
       }

Name and version of the database you are using:
RDBMS: Microsoft SQL Server, version: 08.00.0760
JDBC driver: jTDS Type 4 JDBC Driver for MS SQL Server and Sybase, version: 1.0.3

c3p0

Code:

(openseas) [080605-193209] - (C3P0Registry.java:77) - Initializing c3p0-0.9.0-pre6 [built 10-May-2005 20:32:30 -0400; debug? true; trace: 10]
(openseas) [080605-193210] - (PoolBackedDataSource.java:257) - Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@b8fba5 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@8c6e04 [ acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 8c6e04, idleConnectionTestPeriod -> 600, initialPoolSize -> 2, maxIdleTime -> 1200, maxPoolSize -> 10, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 2, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@1ca5b68 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 1ca5b68, jdbcUrl -> jdbc:jtds:sqlserver://*******, properties -> {user=******, password=******} ], preferredTestQuery -> SELECT 1, propertyCycle -> 300, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies -> false ], factoryClassLocation -> null, identityToken -> b8fba5, numHelperThreads -> 3 ]

Code:

         <property name="hibernate.c3p0.min_size">2</property>
         <property name="hibernate.c3p0.max_size">10</property>
         <property name="hibernate.c3p0.acquire_increment">1</property>
         <property name="hibernate.c3p0.timeout">1200</property>
         <property name="hibernate.c3p0.idle_test_period">600</property>

c3p0 properties

Code:

c3p0.preferredTestQuery = SELECT 1

ThreadLocalPattern method

Code:

public class ThreadLocalSession 
{
    private static final String SESSION_FACTORY_NULL = "SessionFactory not initialised properly!";
    private static final String NO_SESSION = "Unable to create new session";
    private static final Logger logger = Logger.getLogger(ThreadLocalSession.class);
    private static final ThreadLocal sessionContext = new ThreadLocal(); 
   
    private static SessionFactory factory;
    private long level;

    /**
     * 
     */
    private ThreadLocalSession() 
    {
        this.level = 0;
    }
    
    /**
     * 
     */
    public ThreadLocalSession(SessionFactory sessionFactory) 
    {
        this();
        factory = sessionFactory;
    }
    
    public Session currentSession()
    {
        if(factory == null)  {
            factory = new Configuration().configure().buildSessionFactory();
        }
        
        Session session = (Session)sessionContext.get();
      if (session == null) {         
         session = factory.openSession();
      }
      else
      {
          if(!session.isConnected())
              session.reconnect();
      }

      sessionContext.set( session );
      
      level++;

    return session;
    }

    public void closeSession()
    {
        Session session = (Session)sessionContext.get();
        
        level--;

        if(level <= 0)
       {
            sessionContext.set( null );
           if(session != null && session.isOpen()) {
               session.close();
           }
       }
    }
}

Im using the "c3p0.timeout" property so that connections are closed after a period of inactivity. Im also making sure that session.close() is called after a http request is served using a fitler.

However, I notice that connections remain established even after the time specified in the timeout property.

Also, if the database is restarted for some other reason or the connection is interrupted, connection pool is growing bigger while connections still shown as established although there is no physical connection with the server.

Even after the db server is up, the application still doesnt retrieve any data since the connection pool is maxed out but with non working connections

swaldman · **Joined:** Tue Jan 06, 2004 8:58 pm **Posts:** 145

mcueh,

Thanks for the (exemplary) detailed report, and sorry for the slow reponse time!

1) how much longer do you observe Connections lasting than your timeout/maxIdleTime? and are you sure your Connections are truly idle? Note that this isn't an absolute expiration time; the countdown to cull the Connection will reset upon any attempt to use the Connection. Also, the maxIdleTime is not exact -- the actual cull might occur up to plus or minus ~25% of the time (20 minutes) that you've specified.

2) although you have configured a preferredTestQuery, you have configured only a very gentle regime of Connection testing. Idle connections are tested about every 10 minutes, and if there are clients checking out and returning these Connections, bad Connections might last even longer than that. (Ordinarly c3p0 would notice broken Connections over the course of clients' attempt to use them, but if clients occasionally checkout and return the Connection without error, idle times could be reset indefinitely.) Two good Connection testing regimes are frequent idle Connection tests combined with setting testConnectionOnCheckin to true, or simply testConnectionOnCheckout and a fast preferredTestQuery. The latter is simple but exacts a constant, synchronous performance penalty (ok if your test query is fast, not okay otherwise). The former does all testing asynchronously (not in client threads), but involves a tradeoff between frquency of idle Conection testing and the likelihood a client will see a stale Connection. Anyway, you may see more speedy recovery from a database reset with a more vigorous Connection testing regime in place. (Connection testing strategies are discussed in c3p0's docs.)

Hope this helps, and sorry again for the long delay!

smiles,
Steve (c3p0 guy)

alin_sinpalean · **Posted:** Wed Jun 22, 2005 8:24 am

Steve,

I think the issue was caused by a deadlock in jTDS because of an interrupted flag being set (by c3p0) during an execute call. This issue has been fixed in the last release (1.1) and I think mcueh has confirmed in another thread that this seems to have resolved the issue.

Alin,
The jTDS Project.

mschipperheyn · **Joined:** Wed Nov 05, 2003 7:22 pm **Posts:** 211

Hi,

I resolved many of my deadlock issues by upgrading to the jdts 1.1 version. I'm using c3p0 9.0pre6

However, I do encounter them still and when they occur they slow down the system to a crawl with timeout galore.

On my box I have currently 5 identical webapps with different databases running in a single VM. We are currently in a minimal production stage where there is very little traffic.

Each has an identical c3p0 thread pool.

c3p0 thread pool configuration

c3p0.acquireRetryDelay=1000
c3p0.acquireRetryAttempts=60
c3p0.breakAfterAcquireFailure=false
c3p0.preferredTestQuery=SELECT 1
c3p0.testConnectionOnCheckin=true

Hibernate config

<property name="dialect">net.sf.hibernate.dialect.MySQLDialect</property>
<property name="connection.driver_class">com.mysql.jdbc.Driver</property>
<property name="connection.url">jdbc:mysql://localhost/reiderland_export</property>
<property name="connection.username">root</property>
<property name="connection.password">admin</property>
<property name="show_sql">true</property>
<property name="cache.provider_class">net.sf.hibernate.cache.OSCacheProvider</property>
<property name="cache.use_query_cache">true</property>
<property name="cache.use_minimal_puts">false</property>

<property name="c3p0.idle_test_period">3000</property>
<property name="c3p0.min_size">1</property>
<property name="c3p0.max_size">100</property>
<property name="c3p0.max_statements">100</property>
<property name="c3p0.min_size">10</property>
<property name="c3p0.timeout">100</property>
....

WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner : com.mchange.v2.async.T
hreadPoolAsynchronousRunner$DeadlockDetector@1ee1ec7 -- APPARENT DEADLOCK!!! Com
plete Status: [num_managed_threads: 3, num_active: 3; activeTasks: com.mchange.v
2.resourcepool.BasicResourcePool$5@f3cfea (com.mchange.v2.async.ThreadPoolAsynch
ronousRunner$PoolThread-#1), com.mchange.v2.resourcepool.BasicResourcePool$5@d72
0a7 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2), com.mchan
ge.v2.resourcepool.BasicResourcePool$5@1a0c3c2 (com.mchange.v2.async.ThreadPoolA
synchronousRunner$PoolThread-#0); pendingTasks: com.mchange.v2.resourcepool.Basi
cResourcePool$5@194152a, com.mchange.v2.resourcepool.BasicResourcePool$AcquireTa
sk@f97b42, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@10b4954, com.mchange.
v2.c3p0.stmt.GooGooStatementCache$2@1fb39b8, com.mchange.v2.c3p0.stmt.GooGooStat
ementCache$2@8a6e68, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@569b41, com
.mchange.v2.c3p0.stmt.GooGooStatementCache$2@1eafdeb, com.mchange.v2.c3p0.stmt.G
ooGooStatementCache$2@c45670, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@6f
341, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@4c5765, com.mchange.v2.c3p0
.stmt.GooGooStatementCache$2@1fdd73a, com.mchange.v2.resourcepool.BasicResourceP
ool$AcquireTask@3d2d24, com.mchange.v2.resourcepool.BasicResourcePool$AcquireTas
k@5ea3f1, com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@15d36e5, com
.mchange.v2.resourcepool.BasicResourcePool$6@befc44, com.mchange.v2.resourcepool
.BasicResourcePool$AcquireTask@a3ed5c, com.mchange.v2.resourcepool.BasicResource
Pool$AcquireTask@34594c, com.mchange.v2.resourcepool.BasicResourcePool$AcquireTa
sk@d2b5b7]

Any ideas?

Kind regards,

Marc

alin_sinpalean · **Posted:** Tue Jun 28, 2005 9:08 am

Marc,

Press Ctrl+Break (not Ctrl+C) in the command prompt window to obtain a complete thread dump when you suspect you have a deadlock. Post the resulting dumps and we might be able to help.

Alin,
The jTDS Project.

mschipperheyn · **Joined:** Wed Nov 05, 2003 7:22 pm **Posts:** 211

Any clever way to make sure I can copy everything to the clipboard. It's too much and it scrolls out of view. It doesn't show up in the stdout.log

"Java2D Disposer" daemon prio=10 tid=0x289C4C28 nid=0x6c8 in Object.wait() [29a0
f000..29a0fd88]
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
- locked <07EF7860> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
at sun.java2d.Disposer.run(Disposer.java:97)
at java.lang.Thread.run(Thread.java:536)

"AWT-Windows" daemon prio=7 tid=0x28D7FDD8 nid=0x55c runnable [299cf000..299cfd8
8]
at sun.awt.windows.WToolkit.eventLoop(Native Method)
at sun.awt.windows.WToolkit.run(WToolkit.java:253)
at java.lang.Thread.run(Thread.java:536)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2" daemon prio=5
tid=0x288C1990 nid=0x53c in Object.wait() [2994f000..2994fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <061333C0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1" daemon prio=5
tid=0x289B3858 nid=0x39c in Object.wait() [2990f000..2990fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <061333C0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0" daemon prio=5
tid=0x289B3700 nid=0x51c in Object.wait() [298cf000..298cfd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <061333C0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"http-80-Processor8" daemon prio=5 tid=0x2793E8A0 nid=0x630 in Object.wait() [29
88f000..2988fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06C58EF8> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06C58EF8> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor7" daemon prio=5 tid=0x27A8B668 nid=0x614 in Object.wait() [29
84f000..2984fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06C58F78> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06C58F78> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor6" daemon prio=5 tid=0x27A8B4F8 nid=0x6ac in Object.wait() [29
80f000..2980fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06C58FF8> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06C58FF8> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor5" daemon prio=5 tid=0x27F5A998 nid=0x6b8 runnable [297cf000..
297cfd88]
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
- locked <05182420> (a java.net.PlainSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:439)
at java.net.ServerSocket.accept(ServerSocket.java:410)
at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(De
faultServerSocketFactory.java:60)
at org.apache.tomcat.util.net.PoolTcpEndpoint.acceptSocket(PoolTcpEndpoi
nt.java:368)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java
:549)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:683)
at java.lang.Thread.run(Thread.java:536)

"Thread-28" daemon prio=5 tid=0x27D78E08 nid=0x294 in Object.wait() [296cf000..2
96cfd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <068AB1D8> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"http-80-Monitor" prio=5 tid=0x27B8B570 nid=0x564 in Object.wait() [2868f000..28
68fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06636350> (a org.apache.tomcat.util.threads.ThreadPool$Mon
itorRunnable)
at org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable.run(ThreadP
ool.java:559)
- locked <06636350> (a org.apache.tomcat.util.threads.ThreadPool$Monitor
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor4" daemon prio=5 tid=0x27B8B418 nid=0x66c in Object.wait() [28
64f000..2864fd88]
at java.lang.Object.wait(Native Method)
- waiting on <066363D8> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <066363D8> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor3" daemon prio=5 tid=0x27B97768 nid=0x5ac in Object.wait() [28
60f000..2860fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06636458> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06636458> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor2" daemon prio=5 tid=0x27E01C68 nid=0x454 in Object.wait() [28
5cf000..285cfd88]
at java.lang.Object.wait(Native Method)
- waiting on <066364D8> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <066364D8> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor1" daemon prio=5 tid=0x27B97010 nid=0x6a8 in Object.wait() [28
58f000..2858fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06636558> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06636558> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"Thread-18" daemon prio=5 tid=0x27C1AC10 nid=0x600 in Object.wait() [2848f000..2
848fd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <065DE088> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"ContainerBackgroundProcessor[StandardEngine[Standalone storefront]]" daemon pri
o=5 tid=0x279FD940 nid=0x74 waiting on condition [2844f000..2844fd88]
at java.lang.Thread.sleep(Native Method)
at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.r
un(ContainerBase.java:1597)
at java.lang.Thread.run(Thread.java:536)

"Thread-17" prio=5 tid=0x27D90E50 nid=0x668 waiting on condition [2840f000..2840
fd88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"Thread-13" daemon prio=5 tid=0x27BB0DC0 nid=0x64c runnable [2830f000..2830fd88]

at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <06133448> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"Thread-12" prio=5 tid=0x27A68140 nid=0x2d4 waiting on condition [282cf000..282c
fd88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2" daemon prio=5
tid=0x279EE568 nid=0x63c in Object.wait() [2828f000..2828fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <05CEDD48> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1" daemon prio=5
tid=0x279EE410 nid=0x6c4 in Object.wait() [2824f000..2824fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <05CEDD48> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0" daemon prio=5
tid=0x27C6C598 nid=0xfc in Object.wait() [2820f000..2820fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <05CEDD48> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"Thread-8" daemon prio=5 tid=0x27C64A28 nid=0x458 runnable [281cf000..281cfd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <05CECAE8> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"Thread-7" prio=5 tid=0x27A59E30 nid=0x6b0 waiting on condition [2818f000..2818f
d88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"Thread-6" prio=5 tid=0x27467AD0 nid=0x3fc waiting on condition [2814f000..2814f
d88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"Thread-2" daemon prio=5 tid=0x26D53B20 nid=0x140 in Object.wait() [2784f000..27
84fd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <057F07C8> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"Thread-1" prio=5 tid=0x273FC058 nid=0x60c waiting on condition [2780f000..2780f
d88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"Signal Dispatcher" daemon prio=10 tid=0x007F6CE8 nid=0x1cc waiting on condition
[0..0]

"Finalizer" daemon prio=9 tid=0x00845C88 nid=0x5a0 in Object.wait() [26c3f000..2
6c3fd88]
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
- locked <0509EC08> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x00844800 nid=0x1e8 in Object.wait() [26
bff000..26bffd88]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:426)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:113)
- locked <0509EC70> (a java.lang.ref.Reference$Lock)

"main" prio=5 tid=0x002356A0 nid=0x56c runnable [6f000..6fc40]
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
- locked <06687638> (a java.net.PlainSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:439)
at java.net.ServerSocket.accept(ServerSocket.java:410)
at org.apache.catalina.core.StandardServer.await(StandardServer.java:513
)
at org.apache.catalina.startup.Catalina.await(Catalina.java:619)
at org.apache.catalina.startup.Catalina.start(Catalina.java:579)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
sorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:287)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:425)

"VM Thread" prio=5 tid=0x008435C8 nid=0x12c runnable

"VM Periodic Task Thread" prio=10 tid=0x007F51C0 nid=0x288 waiting on condition

"Suspend Checker Thread" prio=10 tid=0x007F6300 nid=0x450 runnable

alin_sinpalean · **Posted:** Wed Jun 29, 2005 6:35 am

I think you can right click on the command prompt window icon (top left) and select "Properties" then increase the buffer size (number of lines).

From the (partial?) thread dump you posted there seems to be no deadlock.

Alin,
The jTDS Project.

mcueh · **Joined:** Wed May 05, 2004 3:26 am **Posts:** 25

Thank god for the reply...I had lost faith really.

swaldman just now I noticed your post (see above).
1. I haven't done any detailed measurements. I could do now that jtds 1.1 is out though.

2. I understand what you're saying but imagine that all Im doing at the moment to test this is having lots of post requests sent to the server, observe the cpool size increasing and then waiting for c3p0 to act after the specified idle time.

alin_sinpalean, what you say its true, but to be honest just now Im trying the 1.1 version of jtds in full length.

Ill give 1.1 jtds a shot and post the results.
Thanks again.

mschipperheyn · **Joined:** Wed Nov 05, 2003 7:22 pm **Posts:** 211

Finally got it:
WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner : com.mchange.v2.async.T
hreadPoolAsynchronousRunner$DeadlockDetector@cbd947 -- APPARENT DEADLOCK!!! Crea
ting emergency threads for unassigned pending tasks!
WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner : com.mchange.v2.async.T
hreadPoolAsynchronousRunner$DeadlockDetector@cbd947 -- APPARENT DEADLOCK!!! Comp
lete Status: [num_managed_threads: 3, num_active: 3; activeTasks: com.mchange.v2
.resourcepool.BasicResourcePool$5@c5c86f (com.mchange.v2.async.ThreadPoolAsynchr
onousRunner$PoolThread-#2), com.mchange.v2.resourcepool.BasicResourcePool$5@ea01
3e (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1), com.mchang
e.v2.resourcepool.BasicResourcePool$5@f7c23b (com.mchange.v2.async.ThreadPoolAsy
nchronousRunner$PoolThread-#0); pendingTasks: com.mchange.v2.resourcepool.BasicR
esourcePool$AcquireTask@1f0b623, com.mchange.v2.resourcepool.BasicResourcePool$5
@45e403, com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7cb569, com.m
change.v2.c3p0.stmt.GooGooStatementCache$3@16a3d44, com.mchange.v2.c3p0.stmt.Goo
GooStatementCache$2@1dc7795, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@12e
e05c, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@8bc909, com.mchange.v2.c3p
0.stmt.GooGooStatementCache$2@13b744e, com.mchange.v2.c3p0.stmt.GooGooStatementC
ache$2@50c415, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@794c32, com.mchan
ge.v2.c3p0.stmt.GooGooStatementCache$2@1797d6d, com.mchange.v2.c3p0.stmt.GooGooS
tatementCache$2@119a7de, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@15bf901
, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@138b67a, com.mchange.v2.c3p0.s
tmt.GooGooStatementCache$2@542610, com.mchange.v2.c3p0.stmt.GooGooStatementCache
$2@8f056e, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@1ada420, com.mchange.
v2.c3p0.stmt.GooGooStatementCache$2@f26f48, com.mchange.v2.c3p0.stmt.GooGooState
mentCache$2@681cfa, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@14674c8, com
.mchange.v2.c3p0.stmt.GooGooStatementCache$2@9d36b9, com.mchange.v2.c3p0.stmt.Go
oGooStatementCache$2@173ba5c, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@cf
f904, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@1e5a743, com.mchange.v2.c3
p0.stmt.GooGooStatementCache$2@485c2d, com.mchange.v2.c3p0.stmt.GooGooStatementC
ache$2@9bab39, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@636c7, com.mchang
e.v2.c3p0.stmt.GooGooStatementCache$2@1f666bb, com.mchange.v2.c3p0.stmt.GooGooSt
atementCache$2@1d2a0d2, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@13c4736,
com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@672ce9, com.mchange.v2.c3p0.stm
t.GooGooStatementCache$2@1b591ec, com.mchange.v2.c3p0.stmt.GooGooStatementCache$
2@17f5d6e, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@ceeedc, com.mchange.v
2.c3p0.stmt.GooGooStatementCache$2@1a3d1d5, com.mchange.v2.c3p0.stmt.GooGooState
mentCache$2@25158a, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@a91719, com.
mchange.v2.c3p0.stmt.GooGooStatementCache$2@12b6bac, com.mchange.v2.c3p0.stmt.Go
oGooStatementCache$2@1a9ff58, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@1b
b02da, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@b857ec, com.mchange.v2.c3
p0.stmt.GooGooStatementCache$2@947682, com.mchange.v2.c3p0.stmt.GooGooStatementC
ache$2@f0770e, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@11865c0, com.mcha
nge.v2.c3p0.stmt.GooGooStatementCache$2@c02a0b, com.mchange.v2.c3p0.stmt.GooGooS
tatementCache$2@84c0d, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@b8f2ba, c
om.mchange.v2.c3p0.stmt.GooGooStatementCache$2@47c1eb, com.mchange.v2.c3p0.stmt.
GooGooStatementCache$2@10c4c45, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@
635a0a, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@ac5308, com.mchange.v2.c
3p0.stmt.GooGooStatementCache$2@17f4400, com.mchange.v2.c3p0.stmt.GooGooStatemen
tCache$2@498cfb, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@c6c13f, com.mch
ange.v2.c3p0.stmt.GooGooStatementCache$2@b91fe8, com.mchange.v2.c3p0.stmt.GooGoo
StatementCache$2@1dde5d9, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@11d3bc
1, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@3e1411, com.mchange.v2.c3p0.s
tmt.GooGooStatementCache$2@1977cbb, com.mchange.v2.c3p0.stmt.GooGooStatementCach
e$2@7ddad4, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@a9bc8e, com.mchange.
v2.c3p0.stmt.GooGooStatementCache$2@19a237d, com.mchange.v2.c3p0.stmt.GooGooStat
ementCache$2@8ff3c0, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@cbe35d, com
.mchange.v2.c3p0.stmt.GooGooStatementCache$2@1bc049e, com.mchange.v2.c3p0.stmt.G
ooGooStatementCache$2@d3398d, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@16
789a4, com.mchange.v2.c3p0.stmt.GooGooStatementCache$2@7d94a8]
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
116322815 milliseconds on: http://ddb2.dmz.tfe.nl/woerden/editorProductCreationD
isplay.do?methodToCall=update&itemId=69
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
116386446 milliseconds on: http://ddb2.dmz.tfe.nl/woerden/productUpdateAction.do
?
WARN org.apache.struts.util.RequestUtils : No FormBeanConfig found under 'edito
rProductDisplay'
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
116387097 milliseconds on: http://ddb2.dmz.tfe.nl/woerden/editorProductHome.do?
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
116438831 milliseconds on: http://ddb2.dmz.tfe.nl/woerden/editorProductCreationD
isplay.do?methodToCall=update&itemId=22
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
116694008 milliseconds on: http://ddb2.dmz.tfe.nl/woerden/productUpdateAction.do
?
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
117734715 milliseconds on: http://ddb2.dmz.tfe.nl/winschoten/fileUploadDisplay.d
o?
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
117828349 milliseconds on: http://ddb2.dmz.tfe.nl/winschoten/fileUpload.do?
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
117925409 milliseconds on: http://ddb2.dmz.tfe.nl/winschoten/displayUploadFiles.
do?
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
117965517 milliseconds on: http://ddb2.dmz.tfe.nl/winschoten/fileUpload.do?
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
117967499 milliseconds on: http://ddb2.dmz.tfe.nl/winschoten/displayUploadFiles.
do?
WARN nl.tfe.ddb.util.HibernateTilesProcessor : High page processing time!: 1120
118110084 milliseconds on: http://ddb2.dmz.tfe.nl/winschoten/regulationFileUploa
d.do?
Full thread dump Java HotSpot(TM) Client VM (1.4.1_01-b01 mixed mode):

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2" daemon prio=5
tid=0x27B6FE98 nid=0x664 in Object.wait() [2cecf000..2cecfd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <068AAE60> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1" daemon prio=5
tid=0x28F2AE70 nid=0x674 in Object.wait() [2ce8f000..2ce8fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <068AAE60> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0" daemon prio=5
tid=0x27EA8D98 nid=0x658 in Object.wait() [2ce4f000..2ce4fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <068AAE60> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2" daemon prio=5
tid=0x28D88C20 nid=0x688 in Object.wait() [2ce0f000..2ce0fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <065DDDD0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1" daemon prio=5
tid=0x28ECE610 nid=0x114 in Object.wait() [2cdcf000..2cdcfd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <065DDDD0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0" daemon prio=5
tid=0x27D1B750 nid=0x1c8 in Object.wait() [2cd8f000..2cd8fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <065DDDD0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2" daemon prio=5
tid=0x27767E58 nid=0x1f0 in Object.wait() [2c5cf000..2c5cfd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <057EF6F0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1" daemon prio=5
tid=0x28ED8C20 nid=0x330 in Object.wait() [2c58f000..2c58fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <057EF6F0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0" daemon prio=5
tid=0x28FA5CB8 nid=0x5c4 in Object.wait() [2c54f000..2c54fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <057EF6F0> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"Java2D Disposer" daemon prio=10 tid=0x289C4C28 nid=0x6c8 in Object.wait() [29a0
f000..29a0fd88]
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
- locked <07DE52F0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
at sun.java2d.Disposer.run(Disposer.java:97)
at java.lang.Thread.run(Thread.java:536)

"AWT-Windows" daemon prio=7 tid=0x28D7FDD8 nid=0x55c runnable [299cf000..299cfd8
8]
at sun.awt.windows.WToolkit.eventLoop(Native Method)
at sun.awt.windows.WToolkit.run(WToolkit.java:253)
at java.lang.Thread.run(Thread.java:536)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2" daemon prio=5
tid=0x288C1990 nid=0x53c in Object.wait() [2994f000..2994fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <06133190> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1" daemon prio=5
tid=0x289B3858 nid=0x39c in Object.wait() [2990f000..2990fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <06133190> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0" daemon prio=5
tid=0x289B3700 nid=0x51c in Object.wait() [298cf000..298cfd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <06133190> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"http-80-Processor8" daemon prio=5 tid=0x2793E8A0 nid=0x630 in Object.wait() [29
88f000..2988fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06C56308> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06C56308> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor7" daemon prio=5 tid=0x27A8B668 nid=0x614 in Object.wait() [29
84f000..2984fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06C56388> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06C56388> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor6" daemon prio=5 tid=0x27A8B4F8 nid=0x6ac in Object.wait() [29
80f000..2980fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06C56408> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06C56408> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor5" daemon prio=5 tid=0x27F5A998 nid=0x6b8 runnable [297cf000..
297cfd88]
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
- locked <05182420> (a java.net.PlainSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:439)
at java.net.ServerSocket.accept(ServerSocket.java:410)
at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(De
faultServerSocketFactory.java:60)
at org.apache.tomcat.util.net.PoolTcpEndpoint.acceptSocket(PoolTcpEndpoi
nt.java:368)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java
:549)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:683)
at java.lang.Thread.run(Thread.java:536)

"Thread-28" daemon prio=5 tid=0x27D78E08 nid=0x294 in Object.wait() [296cf000..2
96cfd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <068AAEE8> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"http-80-Monitor" prio=5 tid=0x27B8B570 nid=0x564 in Object.wait() [2868f000..28
68fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06636120> (a org.apache.tomcat.util.threads.ThreadPool$Mon
itorRunnable)
at org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable.run(ThreadP
ool.java:559)
- locked <06636120> (a org.apache.tomcat.util.threads.ThreadPool$Monitor
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor4" daemon prio=5 tid=0x27B8B418 nid=0x66c runnable [2864f000..
2864fd88]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at org.apache.coyote.http11.InternalInputBuffer.fill(InternalInputBuffer
.java:737)
at org.apache.coyote.http11.InternalInputBuffer.parseRequestLine(Interna
lInputBuffer.java:398)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java
:761)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.proce
ssConnection(Http11Protocol.java:705)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java
:577)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:683)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor3" daemon prio=5 tid=0x27B97768 nid=0x5ac in Object.wait() [28
60f000..2860fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06636228> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06636228> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor2" daemon prio=5 tid=0x27E01C68 nid=0x454 in Object.wait() [28
5cf000..285cfd88]
at java.lang.Object.wait(Native Method)
- waiting on <066362A8> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <066362A8> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"http-80-Processor1" daemon prio=5 tid=0x27B97010 nid=0x6a8 in Object.wait() [28
58f000..2858fd88]
at java.lang.Object.wait(Native Method)
- waiting on <06636328> (a org.apache.tomcat.util.threads.ThreadPool$Con
trolRunnable)
at java.lang.Object.wait(Object.java:426)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:655)
- locked <06636328> (a org.apache.tomcat.util.threads.ThreadPool$Control
Runnable)
at java.lang.Thread.run(Thread.java:536)

"Thread-18" daemon prio=5 tid=0x27C1AC10 nid=0x600 in Object.wait() [2848f000..2
848fd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <065DDE58> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"ContainerBackgroundProcessor[StandardEngine[Standalone storefront]]" daemon pri
o=5 tid=0x279FD940 nid=0x74 waiting on condition [2844f000..2844fd88]
at java.lang.Thread.sleep(Native Method)
at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.r
un(ContainerBase.java:1597)
at java.lang.Thread.run(Thread.java:536)

"Thread-17" prio=5 tid=0x27D90E50 nid=0x668 waiting on condition [2840f000..2840
fd88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"Thread-13" daemon prio=5 tid=0x27BB0DC0 nid=0x64c in Object.wait() [2830f000..2
830fd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <06133218> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"Thread-12" prio=5 tid=0x27A68140 nid=0x2d4 waiting on condition [282cf000..282c
fd88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2" daemon prio=5
tid=0x279EE568 nid=0x63c in Object.wait() [2828f000..2828fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <05CEDBC8> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1" daemon prio=5
tid=0x279EE410 nid=0x6c4 in Object.wait() [2824f000..2824fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <05CEDBC8> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0" daemon prio=5
tid=0x27C6C598 nid=0xfc in Object.wait() [2820f000..2820fd88]
at java.lang.Object.wait(Native Method)
at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(Thre
adPoolAsynchronousRunner.java:355)
- locked <05CEDBC8> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner
)

"Thread-8" daemon prio=5 tid=0x27C64A28 nid=0x458 in Object.wait() [281cf000..28
1cfd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <05CEC968> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"Thread-7" prio=5 tid=0x27A59E30 nid=0x6b0 waiting on condition [2818f000..2818f
d88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"Thread-6" prio=5 tid=0x27467AD0 nid=0x3fc waiting on condition [2814f000..2814f
d88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"Thread-2" daemon prio=5 tid=0x26D53B20 nid=0x140 in Object.wait() [2784f000..27
84fd88]
at java.lang.Object.wait(Native Method)
at java.util.TimerThread.mainLoop(Timer.java:429)
- locked <057F0688> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:382)

"Thread-1" prio=5 tid=0x273FC058 nid=0x60c waiting on condition [2780f000..2780f
d88]
at java.lang.Thread.sleep(Native Method)
at nl.tfe.ddb.business.application.ProductPriceHelper.run(ProductPriceHe
lper.java:139)
at java.lang.Thread.run(Thread.java:536)

"Signal Dispatcher" daemon prio=10 tid=0x007F6CE8 nid=0x1cc waiting on condition
[0..0]

"Finalizer" daemon prio=9 tid=0x00845C88 nid=0x5a0 in Object.wait() [26c3f000..2
6c3fd88]
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
- locked <0509EC08> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x00844800 nid=0x1e8 in Object.wait() [26
bff000..26bffd88]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:426)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:113)
- locked <0509EC70> (a java.lang.ref.Reference$Lock)

"main" prio=5 tid=0x002356A0 nid=0x56c runnable [6f000..6fc40]
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
- locked <066873C8> (a java.net.PlainSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:439)
at java.net.ServerSocket.accept(ServerSocket.java:410)
at org.apache.catalina.core.StandardServer.await(StandardServer.java:513
)
at org.apache.catalina.startup.Catalina.await(Catalina.java:619)
at org.apache.catalina.startup.Catalina.start(Catalina.java:579)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
sorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:287)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:425)

"VM Thread" prio=5 tid=0x008435C8 nid=0x12c runnable

"VM Periodic Task Thread" prio=10 tid=0x007F51C0 nid=0x288 waiting on condition

"Suspend Checker Thread" prio=10 tid=0x007F6300 nid=0x450 runnable

Any ideas?

Marc

alin_sinpalean · **Posted:** Thu Jun 30, 2005 8:05 am

No idea. I see a lot of threads waiting, but no obvious deadlock. Steve, could you please help out?

Alin.

mcueh · **Joined:** Wed May 05, 2004 3:26 am **Posts:** 25

swaldman wrote:

1) how much longer do you observe Connections lasting than your timeout/maxIdleTime? and are you sure your Connections are truly idle? Note that this isn't an absolute expiration time; the countdown to cull the Connection will reset upon any attempt to use the Connection. Also, the maxIdleTime is not exact -- the actual cull might occur up to plus or minus ~25% of the time (20 minutes) that you've specified.

Almost ~2h since the last usage of a connection, only 1 connection expired. 8 are still marked as "ESTABLISHED" using netstat and "AWAITING_CMD" in the database point of view.

As I said, I just generated lots of requests, had the cpool increased and then let it chill...

Ill enable the DEBUG info of c3p0 and try again.

mcueh · **Joined:** Wed May 05, 2004 3:26 am **Posts:** 25

Ok, here is what I got, as you can see it did find one Connection that was expired and removed it. But what happened after that? As you can see its 2 hours of inactivity.

Code:

(openseas) [010705-152554] - DEBUG - (ThreadLocalSession.java:102) - session level decreased to: 0
(openseas) [010705-152554] - DEBUG - (ThreadLocalSession.java:106) - session level reached below zero. Closing session...
(openseas) [010705-152554] - DEBUG - (NewPooledConnection.java:294) - A Throwable occurred while trying to reset the typeMap property of our Connection to Collections.EMPTY_MAP!
java.sql.SQLException: The Connection.setTypeMap(Map) method is not implemented.
        at net.sourceforge.jtds.jdbc.ConnectionJDBC2.notImplemented(ConnectionJDBC2.java:1330)
        at net.sourceforge.jtds.jdbc.ConnectionJDBC2.setTypeMap(ConnectionJDBC2.java:1925)
        at com.mchange.v2.c3p0.impl.NewPooledConnection.reset(NewPooledConnection.java:290)
        at com.mchange.v2.c3p0.impl.NewPooledConnection.markClosedProxyConnection(NewPooledConnection.java:247)
        at com.mchange.v2.c3p0.impl.NewProxyConnection.close(NewProxyConnection.java:93)
        at org.hibernate.connection.C3P0ConnectionProvider.closeConnection(C3P0ConnectionProvider.java:42)
        at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:327)
        at org.hibernate.jdbc.ConnectionManager.cleanup(ConnectionManager.java:262)
        at org.hibernate.jdbc.ConnectionManager.close(ConnectionManager.java:194)
        at org.hibernate.impl.SessionImpl.close(SessionImpl.java:289)
        at gr.forthnet.services.hibernate.ThreadLocalSession.closeSession(ThreadLocalSession.java:111)
        at gr.forthnet.services.hibernate.HiberDatabase.closeSession(HiberDatabase.java:93)
        at gr.forthnet.services.hibernate.HiberDatabase.commitTrasaction(HiberDatabase.java:122)
        at gr.forthnet.services.hibernate.HiberClient.disconnect(HiberClient.java:74)
        at gr.forthnet.openseas.resources.Openseas.close(Openseas.java:76)
        at gr.forthnet.openseas.filters.InitializationFilter.doFilter(InitializationFilter.java:68)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:213)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256)
        at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
        at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2415)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)
        at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
        at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171)
        at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)
        at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:509)
        at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)
        at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
        at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:223)
        at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:261)
        at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:360)
        at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:604)
        at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:562)
        at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:679)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:619)
        at java.lang.Thread.run(Thread.java:534)
(openseas) [010705-152554] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 8, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-152554] - DEBUG - (ThreadLocalSession.java:112) - session closed
(openseas) [010705-153428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 15:34:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-153428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 8, unused: 1, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-153428] - DEBUG - (NewPooledConnection.java:294) - A Throwable occurred while trying to reset the typeMap property of our Connection to Collections.EMPTY_MAP!
java.sql.SQLException: The Connection.setTypeMap(Map) method is not implemented.
        at net.sourceforge.jtds.jdbc.ConnectionJDBC2.notImplemented(ConnectionJDBC2.java:1330)
        at net.sourceforge.jtds.jdbc.ConnectionJDBC2.setTypeMap(ConnectionJDBC2.java:1925)
        at com.mchange.v2.c3p0.impl.NewPooledConnection.reset(NewPooledConnection.java:290)
        at com.mchange.v2.c3p0.impl.NewPooledConnection.markClosedProxyConnection(NewPooledConnection.java:247)
        at com.mchange.v2.c3p0.impl.NewProxyConnection.close(NewProxyConnection.java:93)
        at com.mchange.v1.db.sql.ConnectionUtils.attemptClose(ConnectionUtils.java:41)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1.testPooledConnection(C3P0PooledConnectionPool.java:182)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1.refurbishIdleResource(C3P0PooledConnectionPool.java:136)
        at com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask.run(BasicResourcePool.java:1379)
        at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:368)
(openseas) [010705-154428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 15:44:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-154428] - DEBUG - (BasicResourcePool.java:1066) - resource age is okay: com.mchange.v2.c3p0.impl.NewPooledConnection@14e5e21 ---> age: 1114408   max: 1200000 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-154428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 15:44:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-154428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 8, unused: 1, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-154428] - DEBUG - (NewPooledConnection.java:294) - A Throwable occurred while trying to reset the typeMap property of our Connection to Collections.EMPTY_MAP!
java.sql.SQLException: The Connection.setTypeMap(Map) method is not implemented.
        at net.sourceforge.jtds.jdbc.ConnectionJDBC2.notImplemented(ConnectionJDBC2.java:1330)
        at net.sourceforge.jtds.jdbc.ConnectionJDBC2.setTypeMap(ConnectionJDBC2.java:1925)
        at com.mchange.v2.c3p0.impl.NewPooledConnection.reset(NewPooledConnection.java:290)
        at com.mchange.v2.c3p0.impl.NewPooledConnection.markClosedProxyConnection(NewPooledConnection.java:247)
        at com.mchange.v2.c3p0.impl.NewProxyConnection.close(NewProxyConnection.java:93)
        at com.mchange.v1.db.sql.ConnectionUtils.attemptClose(ConnectionUtils.java:41)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1.testPooledConnection(C3P0PooledConnectionPool.java:182)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1.refurbishIdleResource(C3P0PooledConnectionPool.java:136)
        at com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask.run(BasicResourcePool.java:1379)
        at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:368)
(openseas) [010705-154658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 15:46:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-154658] - DEBUG - (BasicResourcePool.java:1062) - EXPIRED resource: com.mchange.v2.c3p0.impl.NewPooledConnection@14e5e21 ---> age: 1264413   max: 1200000 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-154658] - DEBUG - (BasicResourcePool.java:1024) - Removing expired resource: com.mchange.v2.c3p0.impl.NewPooledConnection@14e5e21 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-154658] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-154928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 15:49:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-155158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 15:51:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-155428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 15:54:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-155428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-155428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 15:54:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-155658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 15:56:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-155928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 15:59:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-160158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:01:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-160428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 16:04:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-160428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-160428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:04:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-160658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:06:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-160928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:09:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-161158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:11:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-161428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 16:14:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-161428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-161428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:14:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-161658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:16:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-161928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:19:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-162158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:21:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-162428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 16:24:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-162428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-162428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:24:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-162658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:26:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-162928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:29:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-163158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:31:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-163428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 16:34:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-163428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-163428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:34:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-163658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:36:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-163928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:39:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-164158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:41:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-164428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 16:44:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-164428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-164428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:44:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-164658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:46:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-164928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:49:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-165158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:51:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-165428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 16:54:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-165428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-165428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:54:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-165658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:56:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-165928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 16:59:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-170158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 17:01:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-170428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 17:04:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-170428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-170428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 17:04:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-170658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 17:06:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-170928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 17:09:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-171158] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 17:11:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-171428] - DEBUG - (BasicResourcePool.java:1326) - Refurbishing idle resources - Fri Jul 01 17:14:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-171428] - DEBUG - (BasicResourcePool.java:1144) - trace com.mchange.v2.resourcepool.BasicResourcePool@10c3a08 [managed: 7, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@12dd538)
(openseas) [010705-171428] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 17:14:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-171658] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 17:16:58 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]
(openseas) [010705-171928] - DEBUG - (BasicResourcePool.java:1271) - Checking for expired resources - Fri Jul 01 17:19:28 EEST 2005 [com.mchange.v2.resourcepool.BasicResourcePool@10c3a08]

nodje · **Posted:** Thu Sep 01, 2005 6:59 am

I just upgraded to c3p0 0.9.0 (from 0.8.5.2)

I'm getting the same exception:

Code:

DEBUG NewPooledConnection:294 - A Throwable occurred while trying to reset the typeMap property of our Connection to Collections.EMPTY_MAP!
com.jnetdirect.jsql.x: Not Supported

I'm using Jnetdirect driver v4.

Do I need the most recent driver to be able to use 0.9.0?

cheers,

swaldman · **Joined:** Tue Jan 06, 2004 8:58 pm **Posts:** 145

Boy. I've missed a lot in this thread. Apologies to all.

The setTypeMap() issue is a non-issue really -- it should be ignored. Since it seems to be annoying a lot of people, I'll modify c3p0 to be more careful about calling the method, but note that the message and stack trace appear at a DEBUG log level. Basically, for drivers that support it, c3p0 has to be careful about calling setTypeMap() [and setReadOnly(), and transactionIsolation, and any other modifiable properties of a Connection] to a standard default before checking them into the pool. Otherwise, the pooled Connections would be non-identical and non-equivalent, leading to strangely different behavior depending on which Connection a client happened to check out. For some of these properties, like typeMap, c3p0 just goes ahead and tries to reset them, ignoring the Exception drivers that do not support the property provoke, other than to dump the stack trace at log level DEBUG.

I'll try to modify this so that c3p0 only tries to reset properties that have successfully been modified.

Re: the "apparent deadlocks" -- I thought this was resolved as of 0.9.0, but obviously it is not. The problem appears to be an interaction between Connection.close() and the Statement cache. If anyone sees an "apparent deadlock" without statement caching enabled, please let me know.

Re: failing to cull very certainly idle resources -- mcueh, i'll try to reproduce your results.

Many apologies to all. I've been out of this and other loops for most of the past few months; c3p0 support, other than to those who've e-mailed me directly, has been minimal. Sorry.

Steve (c3p0 guy)