记一次数据库奔溃重启后 druid 数据源无法恢复连接的生产问题的解决过程

有点绕的标题^_^,事故背景:行里的某减负系统的 oracle 因为不可描述的原因整个虚拟机挂了,故障发生后,所有交易马上从减负系统切回了原系统。经过一段时间的抢修后,数据库恢复了,交易从原系统切回减负系统后,却出现了大量的异常交易,赶紧的又把交易切回了原系统,打开减负系统的日志一看,一堆 getConnection timeout retry 的日志,试着把其中一个应用重启后,连接恢复正常,但是没重启的其他应用服务器都一直在刷 getConnection timeout retry 的日志与错误堆栈 com.alibaba.druid.pool.GetConnectionTimeoutException(……)。

隐隐有些不好的预感。阿里的druid不是能自动恢复连接的吗?但既然清楚了问题所在后,也没头绪,就先把日志打包了回去,期间还抓了4次java core,一同带了回去分析。

看了日志与堆栈,指向的全是获取连接超时的代码段,未能定位问题。不管如何,先看看问题是如何出现的吧,先复现,能复现就能解决。在测试环境上我们试着在交易的过程中,重启虚拟机,重启数据库,的确复现了几乎同样的日志与堆栈,但是只要oracle一恢复服务,连接池就回归正常,无法复现!还有一点让我觉得疑惑的就是上面说的几乎一样的堆栈,实际上我们复现出来的异常堆栈,是带有创建连接异常信息的,但生产上的堆栈却是没有的,百思不得其解。


既然复现无望了,那就读代码吧,对于druid的使用,我们更多的是经验使用,没有真正了解它的原理,这回生产问题紧急,先硬着头皮上了。先从错误堆栈往上推读,找异常的原因,首先是因为ConnectionHolder为空,holder为空是因为获取连接时候返回为空了,而为什么返回为空?要么是因为等待获取超时了,要么是因为连接池中本身就错误地放置了一个null的holder。


看起来好像已经有明目了,但实际上到此处就断了线索了,因为每一种holder的返回都有复杂的情况条件,我仅仅看到代码,没有实际条件参数的辅助判断,根本就不知道问题所在。但实在也没有更多的办法,只能先继续了解druid的原理,继续读它的代码。期间了解到,druid 是使用两个独立线程做连接的创建与回收的,通过执行一段无限循环的代码,它巧妙的使用了empty与notEmpty两个对象的等待与唤醒机制,当无需连接时候,使用empty wait挂起创建连接的线程,而当连接池需要连接的时候,发送empty信号,然后使用 notEmpty wait使获取线程等待,创建连接的线程empty wait收到empty释放信号后,马上进行连接创建,成功后把连接加到池里,同时发出 notEmpty的信号,这时获取连接的线程就会被唤醒,获取刚刚创建的新连接。


代码读过了,但是依然无解,无法解释为何会没有发生创建的异常,却一直没有获取到连接,留给我们解决的时间不多了。这时候我们唯有祭出阿里的调试好器 arthas(一个线上debug工具,甚至更强),拉上组里面会使用这个工具的同事到生产环境去解决问题。


使用arthas attack 到生产的程序后,首先我们观察了连接池的情况,正常!没有连接,连接池数量计算器也显示是0,排除了连接池异常放置连接的可能!接下来,只有一种情况可能返回空,就是获取连接过程中的 notEmpty 等待超时,程序显式返回null。


那么为什么在线程发出了空信号后,创建连接的线程没有在超时时间内为其创建出连接呢?数据库是好的,而且druid没有收集到创建异常。这时候我们再次使用arthas直接调用了创建连接的方法,成功创建,操作系统与数据库之间多了一条连接!这就让我们就有点懵逼了,难道是druid的代码设计出问题了?收到了信号,但线程却没有被唤醒,导致一直没有创建连接?


到此处又断了线索,但组里面的另一位大神在观察系统线程时候,我们发现创建连接的线程是正在运行的,而不是 time wait的,当时没太留意,就是仅仅好奇。就这样后面也没太大进展,使用arthas当晚,应用投产新功能,重启了所有的机器,至此所有的现场消失,原因也仍然没找到。


隔天后不甘心,重新打开了前两天获取的 java core 再分析,突然发现创建连接线程的堆栈也在我们抓取的堆栈里面,而且也是 runnable 状态,并不是没有创建连接时候的 time wait状态,我们在不同的时间间隔抓取了4次,这4次均存在这个线程的堆栈,堆栈显示线程运行中,而且正在跑的是 socket 的 read 方法,至此终于开窍,发现其实并非信号量没用,而是上一次进行数据库连接创建时,到进行堆栈抓取,甚至我们使用 arthas 观察那时,创建连接的线程一直卡住了在 read 方法中,所以无论我们发多少信号,因为循环没有往回跑,所以不可能创建新的连接,也不可能产生创建的异常!


最后结论就是因为某种特殊的挂机原因,使底层进行数据库连接时永不返回导致应用无法再创建新连接,从而造成的这次生产事件。


针对这种情况,后续我们一是决定打开所有应用的监控,从应用内部可第一时间发现问题,及时上送报警,无需等交易失败报警再应对异常。二是继续往下追,看是否存在可以设置连接超时时间的可能并验证,添加杜绝该情况再发生的配置。同时这次查错也让我们获益良多,arthas的使用,java core的获取与分析,druid的源码解读等。本次的记录就次结束,算是一次回顾与总结,与大家共同学习进步。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 212,222评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 90,455评论 3 385
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 157,720评论 0 348
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 56,568评论 1 284
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 65,696评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,879评论 1 290
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,028评论 3 409
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,773评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,220评论 1 303
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,550评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,697评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,360评论 4 332
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,002评论 3 315
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,782评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,010评论 1 266
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,433评论 2 360
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,587评论 2 350