踩坑MySQL主从延迟背景下，生产消费未正确处理此类场景，数据消费第一次失败报警，问题得以暴露。

背景

前几天我就收到了这个报警，报警内容：

[恢复][部署平台][我负责的服务PPP][接口响应状态码异常][接口：接口a响应状态码：500看图：https://grafana.be.company.com/d/i4jgtCN7c/kan-ban-ppp?editPanel=141&orgId=1]

系统: 部署平台
策略名称: 接口响应状态码异常
报警描述: 接口：接口a响应状态码：500看图：https://grafana.be.company.com/d/i4jgtCN7c/kan-ban-ppp?editPanel=141&orgId=1
时间: 2021-12-07 10:25:58
持续时间: 3m11s
服务节点: 服务节点全链名
合并数: 1
合并主机:

这个接口是a模块数据变更后，B系统向A系统拉取a模块数据的查询接口。

问题分析排查

首先查日志，根据个人习惯与团队设施操作即可，一般我们使用ELK技术栈或者Linux文本技术工具。

可以看到使用的消息中间件侧的消息索引，这个可以 用来定位消息。

使用的消息中间件侧看到消息进行了重试，第一次失败，而第二次成功。重试容错，对业务侧没有影响。

消息中间件平台可以看到消息重试第二次消费成功

下一步需要确认下第一次报错的原因。初步在本地用postman调用生产这个入参的接口： postman本地测试，接口毫无问题

调用多次，平均耗时<100ms。当时基于此得出结论：接口没有问题，监控为误报【为多次排查埋下伏笔，这也是一个错误的惯性思维】。

20211207初步处理

初步得出结论：以后出现问题继续观察下，此问题无继续排查下去的必要。

20211209再次分析

问题看起来非偶发，需要重新排查。

发现NPE，根据异常栈可直接定位到报错代码行数。

疑点

  1. 对应代码初上线时并无问题，说明是后面某个变更导致的新问题。
  2. 出现了多条这种数据（消息重试第二次才会成功），说明不是巧合，是必现问题。

排查

突然想到项目中前几周上了读写分离的插件，这个动作立即与当时负责的RD确认，MR记录还存在。

到这里问题经过变得清晰：

  1. 消息生产时，数据写入了主库节点。
  2. 消费者通过生产者服务拉数据时，此时MySQL从节点正在异步写数据，所以此时查出的数据为空。

问题解决

  1. 将此NPE异常封装下，错误返回到接口的Response中，消费者可拿到响应码做判断、重试即可。
  2. 如果消息组件支持延迟消费，可以通过配置的方式处理此问题（RocketMQ支持了延迟消费功能）。

反思

  1. 同类问题多次报出，说明不是巧合。
  2. 业务可用性只是问题判断的依据之一，应用中的异常、报警指标也是问题的判断依据，需要兼顾这几个方面。
  3. 每个问题都值得重视。

Ref