记一次线上因线程池堆满导致拒绝请求问题

1.发现问题

早上7点40左右收到告警信息,这时还未有大量用户在线使用,查看服务调用链的时候发现很多请求失败,提示拒绝请求:

ThreadProtectedRequestRouter reject request: request_method=com.xxx.xxx.model.service.rpc.busiRpcService.getInfoById  request_counter=51 =186 max_thread=200

看拒绝服务的这个服务器没有任何的报错,跟其他异常,数据库也没有慢查询,查看调用链每个请求耗时都很短,可以说是服务应该算很稳,然而线程池却堆满了,为啥呢?? 想去昨天有发版,赶紧看了下发版的工程,确实是发了,而且有优化服务的代码上线了,猜想很可能是这次发版的问题。

2.恢复线上问题

由于马上到上班高峰期,一上班将会有大量用户需要使用系统,为了不影响使用,马上联系运维将代码回滚了(太着急也把自己坑了,忘了dump当时线程日志了),回滚后系统马上恢复了。基本上确定是昨天发版的问题,接下来就是漫长的找原因过程了。。。

3.找系统异常原因

首先从Pinpoint上看调用链,这边假设B服务是线程池满的服务,以下图是A服务,A服务调用B服务的时候,先是看到了有一部分调用超时了,过了一段时间,发现全部拒绝访问(此时B服务的线程池已经满了,而且一直没释放,已经完全不能接收请求)。拒绝的请求可以从B服务中看到拒绝的日志,想着从超时的这些请求分析是不是这些请求的某些操作将线程堵塞了,然而跟踪这些请求也并未发现B服务有任何响应缓慢的情况。这个时候就已经很蒙了,调用方发请求,被调用方看服务看日志都很正常,为啥就线程池满了?

(下面的图第一个是被调用方B服务,2.3是调用方A服务的,4是B服务的当时服务器cpu.内存,活动线程等情况)



从图4可以看出, B服务是在5点多的时候,活动线程就一直不断增加,从没减过,我们服务配的最大线程数是200,最后就一直维持在200没增没减。再下这个节点的日志看,线程数也是一直在增加,但是却看不到异常,到线程数达到200之后一段时间,后面的请求就没再进来了。这个时候这个节点就完全不能接收外部任何请求了,因为线程池满了,实际上这个服务进程是还很正常存活的,还能处理其他比如像Mq之类的任务(使用的是其他线程池)。

服务日志看不到有慢的调用,也看不到任何异常信息,线程池中的线程却全部耗尽了,这时已经没法从日志看出东西了。这个时候就想当时线程是都在干什么,为何看不到任何异常,线程就都不见了,这时就很后悔重启服务前没有将当时的进程dump下来,完全不知道到底发生了什么。只能根据异常信息去跟踪代码,但是从代码上只能看出,为何会拒绝请求了,即使线程数未满的情况下,也出现过拒绝请求。

ThreadProtectedRequestRouter reject request: request_method=com.xxx.xxx.model.service.rpc.busiRpcService.getInfoById request_counter=51 =186 max_thread=200

这个异常就是说明当前有186个线程在运行,还未达到最大线程数200,但是已经拒绝了。原因是request_counter=51 这个数值, 这个是某个方法当前正在处理数量统计,在代码上可以看出当某个方法正在处理达到一定数量也会拒绝请求(我们使用的是motan rpc),而且发现打印拒绝的是都是同样的方法,猜想是不是这个方法的逻辑有问题,跟踪代码却也发现不到任何问题。

感觉已经没有办法找出问题来了,想着这个代码我们开发环境已经用很久了,也没有发现问题,是不是请求量不够大,所以不能触发那个请求呢,所以想着模仿并发量比较高的来请求刚刚怀疑的那个方法,然后请求量已经很大也没重现这个问题。

这个时候想着,这样猜也不是办法了,只有重现了当时的情景猜可以看出问题。开发环境重现不了, 就想着在线上部署一个节点来重现这个问题,所以让运维上了一个节点,因为这个不是立马就能触发的,原来也是发版一个晚上之后第二天才触发,猜想这个也要等到第二天才能看到效果,只能叮嘱运维明天再出现问题一定要先dump再回滚代码了!

就在放弃了查这个问题,等明天重现之后再看,去处理其他事情,在开发环境测试的时候,意外发现那个问题居然重现了,太惊喜了。马上用jstack将当前进程dump下来,分析原因。

最终发现是获取redis连接获取不到,又没有配置等待时间,就一直等下去,所以一个个线程进来都在等待获取redis连接,都耗尽了。为什么会获取不到redis连接呢? 是有哪些连接没有关闭吗? 去找了这次发版的代码,发现了一个地方获取了redis连接之后没有关闭连接,至此终于真正找到原因所在了。


4.总结

系统监控:监控系统很重要,有监控系统才能更早发现问题

                pinpoint等调用链能给分析系统运行情况带来很大帮助

经验:若是线程池满了,一定得记得将当时进程的状态dump下来之后再重启服务,才有办法分析具体原因(要熟悉jstack的使用)

            类似获取redis等连接一定要记得关闭,释放资源。。

保持敬畏:生产发布,一定要保持敬畏,做好review

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

推荐阅读更多精彩内容

  • Swift1> Swift和OC的区别1.1> Swift没有地址/指针的概念1.2> 泛型1.3> 类型严谨 对...
    cosWriter阅读 11,094评论 1 32
  • 在什么情况下使用线程池? 使用线程池的好处: 线程池工作原理:为什么要用线程池? 诸如 Web 服务器、数据库服务...
    骏骏的简书阅读 2,972评论 2 60
  • 第6章介绍了任务执行框架, 它不仅能简化任务与线程的生命周期管理, 而且还提供一 种简单灵活的方式将任务的提交与任...
    好好学习Sun阅读 1,169评论 0 2
  • 前段时间遇到这样一个问题,有人问微信朋友圈的上传图片的功能怎么做才能让用户的等待时间较短,比如说一下上传9张图片,...
    加油码农阅读 1,194评论 0 2
  • 人是思想的产物。心里想的是什么,就会变成什么样的人。 生命就是一场体验而已想怎么体验想体验什么都是自己决定的因为种...
    谷马砺兵阅读 879评论 0 0