线上tomcat服务器报错:
现象:
应用在高峰来临的时候报大量报下面的错误。
- org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is
- org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object
- at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:204 )
- at org.springframework.orm.ibatis.SqlMapClientTemplate.executeWithListResult(SqlMapClientTemplate.java:249 )
- at org.springframework.orm.ibatis.SqlMapClientTemplate.queryForList(SqlMapClientTemplate.java:296 )
- ...................
- Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object
- at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:114 )
- at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044 )
- at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:113 )
- at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:190 )
- ... 33 more
- Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
- at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1134 )
- at org.apache.commons.dbcp.AbandonedObjectPool.borrowObject(AbandonedObjectPool.java:79 )
- at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106 )
- ... 36 more
分析错误来源:
查看出错部分源码,发现出现这个问题出现的原因是数据库操作时超时了。
- if (maxWait > 0 && ((System.currentTimeMillis() - starttime) >= maxWait)) {
- synchronized ( this ) {
- // Make sure allocate hasn't already assigned an object
- // in a different thread or permitted a new object to be created
- if (latch.getPair() == null && !latch.mayCreate()) {
- // Remove latch from the allocation queue
- _allocationQueue.remove(latch);
- } else {
- break ;
- }
- }
- throw new NoSuchElementException( "Timeout waiting for idle object" );
- }
查看dbcp的数据源配置如下:
- <property name= "maxWait" ><value> 60000 </value></property>
- <property name="maxIdle" ><value> 14 </value></property>
超时时间为60s,而调用量top的sql响应时间平均都在2~3ms左右,所以主要时间消耗应该是出现在获取数据库连接上面。
查看出现问题时的线程情况,发现线程有个大量的增长,多出了很多个数据库调用的线程,而数据库的连接池仅有14个,而等待队列用的是一个linkedList,及无限队列,如果调用量很大,队列过长,确实会出现大量60stimeout的情况。
然后查找线程池大量增长的原因。应用中有一个对外提供的接口,调用量比较大,而且接口中需要去好几个地方取数据,所以采用了多线程的方式来提高速度,线程池的配置如下。
- executor = new ThreadPoolExecutor( 10 , 50 , 3 , TimeUnit.SECONDS,
- new ArrayBlockingQueue<Runnable>( 200 ));
- executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
corePoolSize=10
maxPoolSize=50
队列类型长度:ArrayBlockingQueue 200
reject策略:CallerRunsPolicy
首 先前10个线程都通过threadFactory.newThread(w)获取新线程来跑,当池已经到达corePoolSize,则会把任务放入到队 列中,已有线程通过获取队列中的任务来执行。当队列放满之后,再来新任务,则会继续通过threadFactory.newThread(w)获取新线程 来执行,直到池到达50(maxPoolSize)。如果这个时候还有任务过来,则会按照设置的rejectedExecutionHandler的策略 来执行(详细可查看ThreadPoolExecutor中的excute方法)。
rejectedExecutionHandler策略很简单,通过调用线程来执行。
当高并发的时候,线程池已经达到max并且队列已满,则确实会出现一个线程的大量增长。
- public static class CallerRunsPolicy implements RejectedExecutionHandler {
- public void rejectedExecution(Runnable r, ThreadPoolExecutor e) {
- if (!e.isShutdown()) {
- r.run();
- }
- }
- }
推断:
高峰来的时候,首先的时候导致数据库调用的线程池增大,整体数据库调用的响应变慢,导致接口的多线程处理部分线程处理速度变慢,任务堆积,直到线程池和队列都满掉,直接通过工作线程来启动,导致更多线程来获取数据库连接线程,队列更长,知道最后,超过60s。
解决:
其实解决很好解决的,这个接口里面存在一个方法误用,本来这种大量调用的接口就不应该直接走数据库的,改成走缓存,问题解决。