c3p0存在严重bug

时间:2022-09-19 23:30:46

开发的系统使用了Spring JdbcTemplate + c3p0组合,在做性能测试的时候出现了严重的性能问题。40的并发访问,开始的时候系统正常,等过了几分钟后,应用程序不能访问了。停止40并发的压力 后,过1分钟左右又可以正常访问应用程序了,很迷茫。后台log文件有警告信息:

Java代码  c3p0存在严重bug
  1. 2011-11-01 13:48:39,378 [com.mchange.v2.async.ThreadPoolAsynchronousRunner:435]  
  2. -[WARN] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@4ec5571b  
  3.  -- APPARENT DEADLOCK!!!   
  4. Complete Status: [num_managed_threads: 10, num_active: 10; activeTasks: com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7dd9d603 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#6), com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@68719f81 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#9), com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7b9f03b8 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#7),  

 把c3p0换为DBCP后,系统可以正常进行性能测试,访问正常,判定c3p0存在bug。

 

上网查找资料,发现很多人也遇到了"APPARENT DEADLOCK"的问题

Java代码  
  1. http://www.iteye.com/topic/71051  
  2. http://www.iteye.com/topic/22160  
  3. http://www.iteye.com/topic/87313  
  4. http://www.iteye.com/topic/429677  
  5. https://forum.hibernate.org/viewtopic.php?f=1&t=947246&sid=ad2b8cc3213c9dac834d81b55bbf6291  

没有找到解决答案,但是基本了解了c3p0的运行原理。c3p0在从连接池中获取和返回连接的时候,采用了异步的处理方式,使用一个线程池来异步的 把返回关闭了(没有真正关闭)的连接放入连接池中。这样就意味着,我们在调用了从c3p0获得的连接的close方法时,不是立即放回池中的,而是放入一 个事件队列中等待c3p0内部的线程池顺序的处理。

 

c3p0中有2个参数和内部的连接池有关,分别是:maxAdministrativeTaskTime、 numHelperThreads

其含义的官方描述在:

Java代码  
  1. http://www.mchange.com/projects/c3p0/index.html  

 

其中maxAdministrativeTaskTime含义中说了c3p0中的很多功能不是由 client threads完成的,是通过内部线程池完成的,如果某些内部功能“挂起”了线程池中的线程,那线程池中的线程将被耗尽,其最后结果就是c3p0停止响应了。

 

其中通过查看c3p0的源码,可以看出那些功能是需要内部线程池处理的:

 

Java代码  
  1. expandPool -- 在扩大池中连接的时候,如管理的连接从20扩大到40个  
  2. shrinkPool -- 在缩小连接池的时候,这个过程需要真正关闭一些连接  
  3. doCheckinManaged -- 把连接返回给连接池  
  4. checkIdleResources -- 定时检查池中的连接  

 

遇到上面的“APPARENT DEADLOCK”警告就是由于c3p0内部线程池的所有线程都被挂起而造成的,因此官方文档说把numHelperThreads设置大一些可以有效避免这个警告。但是这种方法只能延缓问题的出现,并不能避免整个应用被挂起的问题。

仔细查看log日志,会发现都是那些任务占据了宝贵的线程:

 

 

Java代码  
  1. [com.mchange.v2.async.ThreadPoolAsynchronousRunner:435]-[WARN] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@4ec5571b  
  2.  -- APPARENT DEADLOCK!!! Complete Status: [num_managed_threads: 10, num_active: 10;   
  3.  activeTasks:   
  4.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7dd9d603 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#6),   
  5.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@68719f81 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#9),   
  6.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7b9f03b8 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#7),   
  7.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4ad6470 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#4),   
  8.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@139cf776 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0),   
  9.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@263a6e09 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2),   
  10.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@460e247a (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#3),   
  11.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4a7ce984 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1),   
  12.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4ec6ff50 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#5),   
  13.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@6aa40597 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#8);   
  14.  pendingTasks:   
  15.  com.mchange.v2.resourcepool.BasicResourcePool$6@366b3333,   
  16.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@37ee752e,   
  17.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@84f3bb2,   
  18.  com.mchange.v2.resourcepool.BasicResourcePool$6@9d82761,   
  19.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4e015653,   
  20.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@39ca8b27,   
  21.  com.mchange.v2.resourcepool.BasicResourcePool$6@2075cb15,   
  22.  com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@1567e059,   
  23.  com.mchange.v2.resourcepool.BasicResourcePool$6@56b9fe09,   

 可以看到AcquireTask占用了内部线程池的所有线程,没有线程可以来执行BasicResourcePool$6对应的任务,而这个任务的作用就是把池外使用完的连接放回池内的,c3p0被挂起了。

 

maxAdministrativeTaskTime用于定时检查任务列表,如果activeTasks列表在2次检查中一致,那么c3p0就会认为APPARENT DEADLOCK了,会interrept所有任务,重新排队,因此c3p0会自动恢复正常。

 

我的解决方法是用单独的线程来处理“归还”连接的任务,因为这个任务的优先级最高,而且耗费的时间很短。

 

上传我修改后的 c3p0 jar包,只改了一个文件:BasicResourcePool

 

c3p0的确存在问题,大家不要怀疑我写的程序有问题

 

我写了一个测试程序,模拟c3p0在压力很大的时候的运行状态,说明如下:

 

1 JDBC是自己写的一个mock,也就是一个自定义java.sql.Driver,前20个连接马上生成返回,后面的连接需要15秒才能生成(模拟数据库繁忙,生成连接慢)

2 测试线程从1开始,每1秒增加一个测试线程,最终会达到100个线程

3 每一秒种输出一句log,包含的信息有:测试线程数(totalThreads)、正在处理con的线程数(dealConThreads)、处理con的总次数(dealConCount)

 

c3p0配置如下:

Java代码  
  1. cpds.setDriverClass("com.thunisoft.test.jdbcmock.TestDriver");  
  2. cpds.setJdbcUrl( "jdbc:test://192.168.0.1/test" );    
  3. cpds.setUser("user");  
  4. cpds.setPassword("123456");  
  5.           
  6. cpds.setAcquireIncrement(20);  
  7. cpds.setInitialPoolSize(20);  
  8. cpds.setMaxPoolSize(200);  
  9. cpds.setMinPoolSize(20);  

 其中使用c3p0-0.9.1.2.jar在20个线程的时候,基本处于挂起状态了,随后就会报 DEADLOCK 的警告

使用c3p0-0.9.1.2_fix_APPARENT_DEADLOCK.jar也会报 DEADLOCK 的警告,但是不会被挂起,可以继续提供连接给测试线程,只是能提供的线程少于线程总数。

 

发生 DEADLOCK 的前提条件:

1 连接池会进行expandPool操作,因为这样才能产生AcquireTask对象,这个对象会阻塞内部连接池,因此,如果把minPoolSize和maxPoolSize设置为一样大可以避免这个问题

2 AcquireTask的执行持续很长时间,要大于10秒,在实际环境中是有可能放生的

3 acquireIncrement要大于numHelperThreads,这样才有可能把所有内部线程都占用

4 连接池的访问压力要很大,压力线程数要大于连接池现有的连接数