解bug之路-九游会j9官网ag登录入口

3顶
1踩

解bug之路-druid的bug

2017-05-16 10:58 by 副主编 jihong10102006 评论(1) 有7462人浏览
笔者很热衷于解决bug,同时比较擅长(网络/协议)部分,所以经常被唤去解决一些网络io方面的bug。现在就挑一个案例出来,写出分析思路,以飨读者,希望读者在以后的工作中能够少踩点坑。

前言

此bug是druid低版本的bug,此bug至少在1.0.12版本就已经修复。

druid的bug现场

在紧张的新项目开发的日子里,突然收到线上某系统的大量报警,对应系统的人员发现此系统在某一台机器上dump了大量的error日志。日志基本都是:
druid:  getconnectiontimeoutexception

此系统所有用到数据库的地方都抛出此异常。于是祭出重启大法,重启过后,一切okay。然后对应的系统人员开始排查这个问题,一直没有结果。
过了两天,又收到此类型的error日志报警,而且这一次是有两台系统同时爆出此种错误。紧急重启后,将此问题紧急报到我们这边处理。鉴于本人有丰富的io处理经验,当然落到了本人头上。

bug复盘

此系统是通过druid连接后面的数据库分库分表proxy,再由此proxy连接后面的数据库。示意图如下所示:

缩小bug范围

获取连接超时(getconnectiontimeoutexception)此错误的出现,只有两种可能:

1.业务系统本身druid获取连接失败。   
2.作为中间件的sharding proxy获取连接失败。

在这个bug里面很明显是druid创建连接失败,原因如下:

1.此系统有10多台机器,仅仅有两台出现此种故障。   
2.这两台重启后一切正常。

如果说这两台是由于同机房问题出现统一的网络连接异常,那么并不能解释重启后正常这一现象。

druid问题定位

于是开始分析为何获取连接超时,第一步当然是开始寻找源码中日志抛出异常点。上源码:
druidconnectionholder holder;
.......
try {
    if (maxwait > 0) {
       holder = polllast(nanos);
    }
    else {
       holder = takelast();
    }
    ......
}finally {
    lock.unlock();
}
if(holder == null){
   ......
    if (this.createerror != null) {
        throw new getconnectiontimeoutexception(errormessage, createerror);
    } else {
        throw new getconnectiontimeoutexception(errormessage);
    }   
}

可见,这边获取到的druidconnectionholder为null,则抛出异常。

druid获取连接的过程

在分析这个问题之前,先得看下druid是如何创建连接的,下面是本人阅读druid源码后画的示意图:

可见druid创建连接都是通过一个专门的线程来进行的,此图省略了大量的源码细节。

为何holde为null?

继续上源码
private druidconnectionholder polllast(long nanos) throws interruptedexception, sqlexception {
    for (;;) {
        if (poolingcount == 0) {
            emptysignal(); // send signal to createthread create connection
            if (estimate <= 0) {
                waitnanoslocal.set(nanos - estimate);
                return null;
            }
            ...
            try {
                long startestimate = estimate;
                estimate = notempty.awaitnanos(estimate); 
                ......
            } finally {
              ......
            }
            ......
            if (poolingcount == 0) {
                if (estimate > 0) {
                    continue;
                }
                waitnanoslocal.set(nanos - estimate);
                return null;
            }
        }
        decrementpoolingcount();
        druidconnectionholder last = connections[poolingcount];
        connections[poolingcount] = null;
        return last;
    }
}

可见,如果触发条件,estimate<=0,则返回null。
上述源码的过程示意图如下:

继续追踪

由此可见,在获取连接的时候一直超时,不停的爆getconnectiontimeoutexception异常,明显是由于创建连接线程出了问题。那到底除了什么问题呢?由于druid的代码比较多,很难定位问题点,于是还从日志入手。

进一步挖掘日志

错误信息量最大的是最初出现错误的时间点,这是笔者多年排查错误的经验总结。由于正好有两台出错,比较其错误的共同点也能对解决问题大有裨益。
大量create connection error

当笔者和同事追查错误的源头的时候,在有大量的create connection error,奇怪的是,到了一个时间点之后,就只剩getconnectiontimeoutexception异常了。
继续分析,在出现create connection error的时候,还是有部分业务请求能够执行的。即获取到了连接。
翻了翻源码,create connection error是在创建连接线程打印的,如果这个异常没有继续打印,而同时连接也获取不到,就在很大程度上表明:

创建连接根本就是被销毁了!

错误分界点

于是开始寻找什么时候create connection error开始销毁。于是通过笔者和同事在无数的错误日志中用肉眼发现了一个不寻常的日志隐蔽在大量的错误日志间:

druid:create holder error


在这个错误出现之后,就再也没有了create connection error,翻了翻另一台机器的日志,页是同样的现象!

源码寻找bug

隐隐就感觉这个日志是问题错误的关键,打出这个日志的源码为:
创建连接线程
@override
public void run() {
            runinternal();
}
private void runinternal() {
    for (; ; ) {
        ......
        try{
            holder = new druidconnectionholder(druiddatasource.this,connection);
        }catch(sqlexception ex){
            log.error("create connection holder error",ex);
            // 这句break就是罪魁祸首
            // 至少在1.0.12修复
            break;
        }
        ......
    }
}

这边竟然在for(;;)这个死循环中break了!!!,那么这个线程也在break后跳出了死循环从而结束了,也就是说创建连接线程被销毁了!!!如下图所示:

为何create holder error?

继续搜寻日志,发现create holder error之前,会有获取事务隔离级别的报错。那么结合源码,错误的发生如下图:

即在druid的创建连接线程创建连接成功之后,还需要拿去数据库的holdability,isolation(隔离级别)等metadata,在获取metadata失败的时候,则会抛出异常,导致创建连接线程break。
但是如果在handshake的时候就失败,那么由于druid处理了这种异常,打印create connection error,并继续创建连接。
于是就有了在create holder error之前大量create connection error,在这之后没有了的现象。

完结了么?

druid的bug是弄清楚了,但是为何连接如此不稳定,有大量的创建连接异常,甚至于druid前脚创建连接成功,后脚发送命令就失败呢?

sharding proxy的bug

于是此问题又萦绕在笔者心头,在又一番不下于上述过程的努力之后,发现一个月之前上线的新版本的sharding proxy的内存泄露bug导致频繁gc(并定位内存泄露点),导致了上述现象,如下图所示:

由于每次内存泄露过小,同时sharding proxy设置的内存过大。所以上线后过了一个月才有频繁的gc现象。之前上线后,大家观察了一周,发现没有任何异常,就不再关注。与此类似,如果db负载过高的话,笔者推测也会触发druid的bug。

最后处理

笔者去翻druid最新源码,发现此问题已经修复,紧急联系各业务线升级druid,同时让sharding proxy负责人修改了最新代码并上线。
终于这次的连环bug算是填完了。

总结

追查bug,日志和源码是最重要的两个部分。最源头的日志信息量最大,同时要对任何不同寻常的现象都加以分析并推测,最后结合源码,才能最终找出bug。
  • 大小: 76.6 kb
  • 大小: 237.7 kb
  • 大小: 144.8 kb
  • 大小: 42.9 kb
  • 大小: 57 kb
  • 大小: 139 kb
来自:
3
1
评论 共 1 条 请登录后发表评论
1 楼 2017-05-17 15:40
涨见识了哈,可能用不到这个插件,但拓展了解决bug的思路和方法

发表评论

您还没有登录,请您登录后再发表评论

相关推荐

  • 解bug之路-串包bug 笔者很热衷于解决bug,同时比较擅长(网络/协议)部分,所以经常被唤去解决一些网络io方面的bug。现在就挑一个案例出来,写出分析思路,以飨读者,希望读者在以后的工作中能够少踩点坑。 串包bug...

  • 解bug之路-主从切换”未成功”?前言数据库主从切换是个非常有意思的话题。能够稳定的处理主从切换是保证业务连续性的必要条件。今天笔者就来讲讲主从切换过程中一个小小的问题。故障场景最近线上进...

  • 笔者很热衷于解决bug,同时比较擅长(网络/协议)部分,所以经常被唤去解决一些网络io方面的bug。现在就挑一个案例出来,写出分析思路,以飨读者,希望读者在以后的工作中能够少踩点坑。 串包bug现场 前置故障redis超时...

  • druid 1.2.5及以下版本 连接保活bug踩坑

  • } // bug fixed for dead lock, for issue #2980 druiddriver.getinstance(); /**控制创建移除连接的锁,并且通过条件去控制一个连接的生成消费**/ // public druidabstractdatasource(boolean lockfair){ // lock ...

  • 这让对应应用的开发百思不得其解,于是求助了笔者一探究竟。 怎么发现的 应用开发收到cat监控告警,发现这个应用(a)中的请求在好几台机器中一直稳定失败。联想到昨晚刚做过数据库主从切换演练,于是上机器netstat -...

  • 拦截器和过滤器用到了servlet,所以要注册servlet 拦截器主要拦截以/druid/开头的 最后使用localhost://8080/就可以访问监控平台。

  • druid连接池init方法源码解读 今日主要针对druid连接池中的data source核心代码中的初始化方法进行源码解读和学习。尤其针对init方法中的createandstartcreatorthread/createandstartdestroythread线程进行详细的...

  • 1.新建maven web_app项目,名为xxx_druid,在pom.xml中引入druid-1.2.8和mysql-connector-8.0.28以及相关依赖。 pom.xml相关依赖: <dependencies> <dependency> <groupid>com.alibaba<...

  • org.springframework.transaction.cannotcreatetransactionexception: could not open jdbc connection for ... nested exception is com.alibaba.druid.pool.getconnectiontimeoutexception: wait millis ...

  • druid声称是java语言中最好的数据库连接池。spring boot start自动装配组件,简化组件使用,所以druid也推出了druid-spring-boot-starter。 1.pom.xmlyi

  • * @bug [nothing] * @see [nothing] * @备注: */ public class loaddatasource extends abstracthibernatedao { protected final log logger = logfactory.getlog(getclass()); private baseextenddao ...

  • 查找到druid mysqlutis类后发现。出现阻塞原因在于版本不匹配,低版本的driud加载的是com.mysql.jdbc.mysqlconnection,而8.0版本的mysql-connector用的是com.mysql.cj.jdbc.connectionimpl。升级druid到1.2以上版本...

  • python库是一组预先编写的代码模块,旨在帮助开发者实现特定的编程任务,无需从零开始编写代码。这些库可以包括各种功能,如数学运算、文件操作、数据分析和网络编程等。python社区提供了大量的第三方库,如numpy、pandas和requests,极大地丰富了python的应用领域,从数据科学到web开发。python库的丰富性是python成为最受欢迎的编程语言之一的关键原因之一。这些库不仅为初学者提供了快速入门的途径,而且为经验丰富的开发者提供了强大的工具,以高效率、高质量地完成复杂任务。例如,matplotlib和seaborn库在数据可视化领域内非常受欢迎,它们提供了广泛的工具和技术,可以创建高度定制化的图表和图形,帮助数据科学家和分析师在数据探索和结果展示中更有效地传达信息。

  • stm32单片机fpga毕设电路原理论文报告基于ide硬盘的数字图像存储技术研究本资源系百度网盘分享地址

  • 适合rust入门。深入浅出,事无巨细,远胜市面上所有入门书。而且是免费的

  • vb语言vb房屋租凭管理系统毕业设计(源代码 系统)本资源系百度网盘分享地址

  • 这个示例代码,我们实现了一个用 c 语言判断一个数是否为素数的函数,并通过 main() 函数来测试这个函数。整个过程简单明了,代码结构清晰,易于理解和修改。这个示例展示了 c 语言中函数的定义和调用,以及条件判断和循环等基本语法的使用。

  • 层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例层次化网络设计案例

global site tag (gtag.js) - google analytics
网站地图