V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
V2EX 提问指南
312ybj
V2EX  ›  问与答

记一次 P0 bug 修复

  •  
  •   312ybj · 61 天前 · 1120 次点击
    这是一个创建于 61 天前的主题,其中的信息可能已经有所发展或是发生改变。

    问题影响

    今天早上 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
    liprais
        1
    liprais   61 天前
    如果是我的话我第一步就是确认数据库没问题
    shuimugan
        2
    shuimugan   61 天前   ❤️ 2
    运维干的活只有重启和拉日志?那还不如直接上公有云的 serverless 架构,连运维都省了...

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

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

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

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

    当然,这些都很理想,在中华田园敏捷开发的模式下很难搞起来,不然你这个问题在上线前测试流程加一道压测就不会存在了。
    adspe
        3
    adspe   61 天前
    不如好好检讨一下为什么前端会有这个轮询的接口,完全是自己作出来的
    zjj19950716
        4
    zjj19950716   61 天前
    80w 是什么概念
    neptuno
        5
    neptuno   61 天前
    这 sql 看上去是挺慢的,select id from (select b1.id,(select.....))
    312ybj
        6
    312ybj   61 天前
    @shuimugan 大佬一针见血, 佩服佩服
    qionnian
        7
    qionnian   28 天前
    请教一下,第一张图叫什么来着
    关于   ·   帮助文档   ·   API   ·   FAQ   ·   我们的愿景   ·   广告投放   ·   感谢   ·   实用小工具   ·   2478 人在线   最高记录 5497   ·     Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.5 · 29ms · UTC 14:14 · PVG 22:14 · LAX 06:14 · JFK 09:14
    ♥ Do have faith in what you're doing.