10.15 生产事故复盘
1. 10.14发版
10.14 18:05分，清结算系统正常发版，上的是“福建工行保证金需求”和“线下佣金结算”需求。发版内容本身经过测试，无问题。
git中的提交记录比对
发布的重启过程，是杀掉已有线程，并用新包启动线程。 在杀的过程中“重发机制”的一个锁正好没有释放，锁自然存在时间为24小时，锁在redis中，因为业务情况，锁没有释放的情况也很常见。
工具类中redis默认设置为24小时
2. 重发机制的BUG
“重发机制”正常过程是，每10分钟查重发任务，循环发送。一旦遇到有锁的任务正常应对是不处理或抛异常，然后执行下一个任务。
但这里有个严重BUG，遇到redis锁，跳出循环，后面的任务都不执行。
循环中直接return
3. 10.14晚的停卡
10.14晚22:00的停卡定时任务查询到需要停卡的客户号，存入“重发队列”，就因为有一个锁的存在，一条停卡任务都没有推送到ETC。这样持续到了10.15。
10.14应该停卡的用户，是10.13账单没结清的用户。
4. 10.15白天
运营收到很多客户反馈说账单没结清也没有停卡，反馈到IT，其中有些客户赶在白天把应该要停卡的对应的10.13的账单结清了。
数据分析发现10.14的停卡率无法统计，反馈给徐总。
IT在10.15下午17:00左右得知这个问题，开始排查数据和代码。
5. 问题排查期间出现新问题
一开始检查10.14清结算发版引起的，比对代码后没发现任何异常，验证了不是版本迭代引起的。
那只能看停卡任务和重发机制的代码，一行一行地检查逻辑。
傍晚18:25左右，忽然发现804名客户推送的停卡指令发送到了ETC，包含10.14所有的停卡用户，但时隔一天用户状态已经不一样，其中有些已经完成账单结清的客户不该再推送停卡。
重发任务和任务成功时间
6. 问题定位
最终定位到了是重发机制代码24小时锁的Bug。
而重推停卡指令在18:25这个时间点也解释了两个问题：
a） 这个异常的时间点减去24小时，正好是14日发版后的一段时间。18:05加锁未释放，任务调动间隔10分钟一次，算上启动发版和队列中任务执行的时间，这个时间非常吻合。
b） 遇到异常跳出循环，停卡的任务这么巧第一个就遇到锁，导致一个10.14的停卡都没有发送到ETC。
这是因为锁住的任务并不是停卡任务，而所有任务中排在停卡任务队列以前的任务，时间上锁住的任务是14日晚上18:05的任务，而停卡任务是在14日晚上22:00才进入队列的。
由于在15日18:25分，锁已经释放，因此也无法找到当时锁住的具体是哪个任务了。
7. 问题处理
修改循环跳出的BUG，发版。
对804名停卡客户，找到13日、14日账单已经结清的客户，重推复卡指令。
总结：
1. 重发机制异常退出整个循环是个严重的问题
2. 重发机制对锁的使用不合理，锁的时间应当适中，调整在2小时左右。
3. 发版过程中不关注运行情况直接kill有风险，需要优化发版的流程。
4. 停卡复卡这种流程中重要的任务，必须有监控和预警机制。而不是业务部门发现。
5. 批量停卡、批量复卡类似这种后门需要预留，提高修复数据的效率。
网友评论