记一次 P0 bug 修复 - V2EX
V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
312ybj
V2EX    推广

记一次 P0 bug 修复

  •  
  •   312ybj 2021 年 9 月 28 日 2515 次点击
    这是一个创建于 1581 天前的主题,其中的信息可能已经有所发展或是发生改变。

    问题影响

    今天早上 10:50 左右,系统页面突然不能访问,我们是 sass 统,很多租户爆出了同样的错误。问题影响到了租户的使用。

    排查流程

    image.png

    表现

    时间

    2021-09-15 10:50 am

    问题表象

    1. 多个租户素材列表页不显示内容

    1. sentry 发出大量错误日志

    都是同一个项目 general

    排查方法

    由于从报错日志中无法定位业务代码,所以采用相关度排查。

    1. 确认最近的修改

    早上 10:50 左右开始, 从此时间开始推导该时间前后

    1. 上线的项目

    昨晚是有一个项目上线,但是目前没有发现影响

    1. 改过的配置

    没有直接影响

    1. 报错日志

    无法定位问题

    1. 数据量是否有较大变化

    新租户 t247 上线了 80w 新素材,可能会对系统产生压力。

    以上无法直接或间接得出结果

    1. 判断代码&项目问题

    general 模块报错, 但是从报错日志,无法确认是代码逻辑问题导致的错误。

    一开始想找运维重启 general 项目,但是运维告知项目已经自动重启 6 次,重启无法解决问题。

    1. 查看容器节点

    正如运维所说 general 项目在不断的重启, 重启是因为节点的健康检查机制, 连续 5 次 3s 内健康检查请求得不到反馈,容器自动重启。 但是重启后最大请求时间还是居高不下。后来运维关闭健康检查机制。 奇怪的是关闭健康检查机制之后,系统莫名的正常了。但是没有找到正确答案,还是不能放松警惕。此时时间是 11:25 am 左右。

    1. 关注 grafana

    发现请求最大时长可以达到一分半,这个就绝对不正常了。怪不得容器不停重启,肯定是因为请求堵塞了,所以健康检查接口无法得到结果。

    1. 定位请求慢原因(慢 SQL )

    当时项目 CPU 正常,内存正常,垃圾回收正常。 于是将问题归纳到数据库上,联系运维拉取慢日志。慢日志拉下来了。

    慢日志还挺多

    在茫茫日志中,有一个熟悉的数字 t247, 而且不止出现一次。这个 SQL 执行了 49s 。

    当然一个 49s 的慢 SQL 不至于把系统整瘫。

    1. 找人问最近上线事宜

    在第一步中,我们找到最近上线的负责人, 因为他们上线时增加了 80w 数据,而慢 SQL 与数据量也有很大关系。仔细一聊,我们发现了一个要命的问题:前端有个页面,某个接口在会每隔 10s 请求一次 general,而且这个接口很慢。于是我打开了 grafana, 一遍复现这个请求,一遍观察请求速度。不出所料,的确很慢。 随后安排了这个逻辑修复。

    为什么健康检查关闭就好了?

    由后续的检测可以得知:慢 SQL 是拖垮 general 项目的原因。如果 genenral 项目能恢复,那么原因就是慢 SQL 任务执行完毕了。

    在观察慢 SQL 日志时,我发现关闭健康检查的同时( 11:25 am ),关于 t247 租户的慢 SQL 锐减。这基本上就能确定慢 SQL 的锅了。

    总结

    首先遇到较难问题不要慌,积极应对。多个人多份力量,一起分析。

    可以按照上面的排查方法一步一步来。

    1. 查看各个指标监控
    • sentry 项目检测
    • k8s 重启次数
    • Grafana 性能指标
    • 数据库 CPU&内存指标
    • 慢 SQL 检测
    1. 确认最近的修改

    2. 代码与项目状态排查

    3. 针对代码或者项目进行分析

    4. 拉通第一步中人员进行一起分析

    基本上通过这几步问题大致能够定位问题所在,剩下 20%的工作量就是修复 bug 了

    7 条回复    2021-10-31 17:09:16 +08:00
    F281M6Dh8DXpD1g2
        1
    F281M6Dh8DXpD1g2  
       2021 年 9 月 28 日
    如果是我的话我第一步就是确认数据库没问题
    slowgen
        2
    slowgen  
       2021 年 9 月 28 日   2
    运维干的活只有重启和拉日志?那还不如直接上公有云的 serverless 架构,连运维都省了...

    “联系运维拉取慢日志。慢日志拉下来了”
    其实完全可以定时(比如 5min )采集慢日志,收集起来,也就是为什么云厂商总有一个面板给你去看慢日志。

    “仔细一聊,我们发现了一个要命的问题:前端有个页面,某个接口在会每隔 10s 请求一次 general,而且这个接口很慢”
    如果你的网关日志采集了,并且做了阈值告警,这也可以感知出来,这也是为什么云厂商的日志服务里,可以根据查询结果配置告警。

    “general 模块报错, 但是从报错日志,无法确认是代码逻辑问题导致的错误”

    如果 CMDB 之类的信息化建设得好的话,每个项目都有哪些接口,每个接口背后调用了什么资源(比如数据库实例,用的 DB,查的表),每个项目在部署的时候怎么对应容器 Pod 等信息都能知道的话...
    针对文中的 case,从网关日志中捕获到时间长的接口,就可以检索出接口背后在什么容器,负载如何,接口对应的库表当前有什么慢查询,当前版本和上一个版本差异的提交有哪些...各个维度的内容 load 出来一份报告,问题就找得差不多了。
    这时候自动出一个审批单,是否紧急屏蔽这个接口的访问,熔断也好了。

    当然,这些都很理想,在中华田园敏捷开发的模式下很难搞起来,不然你这个问题在上线前测试流程加一道压测就不会存在了。
    adspe
        3
    adspe  
       2021 年 9 月 28 日
    不如好好检讨一下为什么前端会有这个轮询的接口,完全是自己作出来的
    zjj19950716
        4
    zjj19950716  
       2021 年 9 月 28 日
    80w 是什么概念
    neptuno
        5
    neptuno  
       2021 年 9 月 28 日
    这 sql 看上去是挺慢的,select id from (select b1.id,(select.....))
    312ybj
        6
    312ybj  
    OP
       2021 年 9 月 28 日
    @shuimugan 大佬一针见血, 佩服佩服
    qionnian
        7
    qionnian  
       2021 年 10 月 31 日
    请教一下,第一张图叫什么来着
    关于     帮助文档     自助推广系统     博客     API     FAQ     Solana     3181 人在线   最高记录 6679       Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION 3.9.8.5 36ms UTC 13:02 PVG 21:02 LAX 05:02 JFK 08:02
    Do have faith in what you're doing.
    ubao msn snddm index pchome yahoo rakuten mypaper meadowduck bidyahoo youbao zxmzxm asda bnvcg cvbfg dfscv mmhjk xxddc yybgb zznbn ccubao uaitu acv GXCV ET GDG YH FG BCVB FJFH CBRE CBC GDG ET54 WRWR RWER WREW WRWER RWER SDG EW SF DSFSF fbbs ubao fhd dfg ewr dg df ewwr ewwr et ruyut utut dfg fgd gdfgt etg dfgt dfgd ert4 gd fgg wr 235 wer3 we vsdf sdf gdf ert xcv sdf rwer hfd dfg cvb rwf afb dfh jgh bmn lgh rty gfds cxv xcv xcs vdas fdf fgd cv sdf tert sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf shasha9178 shasha9178 shasha9178 shasha9178 shasha9178 liflif2 liflif2 liflif2 liflif2 liflif2 liblib3 liblib3 liblib3 liblib3 liblib3 zhazha444 zhazha444 zhazha444 zhazha444 zhazha444 dende5 dende denden denden2 denden21 fenfen9 fenf619 fen619 fenfe9 fe619 sdf sdf sdf sdf sdf zhazh90 zhazh0 zhaa50 zha90 zh590 zho zhoz zhozh zhozho zhozho2 lislis lls95 lili95 lils5 liss9 sdf0ty987 sdft876 sdft9876 sdf09876 sd0t9876 sdf0ty98 sdf0976 sdf0ty986 sdf0ty96 sdf0t76 sdf0876 df0ty98 sf0t876 sd0ty76 sdy76 sdf76 sdf0t76 sdf0ty9 sdf0ty98 sdf0ty987 sdf0ty98 sdf6676 sdf876 sd876 sd876 sdf6 sdf6 sdf9876 sdf0t sdf06 sdf0ty9776 sdf0ty9776 sdf0ty76 sdf8876 sdf0t sd6 sdf06 s688876 sd688 sdf86