记一次使用Redis Cache引起的Bug排查及修复总结

一次产品需求愉快的上线后，翌日下午有用户反馈，工单流程状态不对，为何不对呢？经过跟用户微信电话沟通，工单提交后，流程子状态应该展示转存量。是的，没有错，业务流程 没有问题，应该是我的程序出现bug了。恰巧上线后翌日，北京气象局多次短信通知，有大暴雨，注意防涝。尽管如此，当日我依然来到公司，排查一些其他反馈问题。室外开始大雨来临， 我收拾电脑准备回家，到家后准备吃饭，微信群又反馈出现几单状态不正确，我回复"刚到家，吃饭后立即排查"。吃饭后，经过电脑前一系列排查最终找到问题，当时已经晚上22点多了。

1.业务概述

 

如上图业务逻辑是这么处理的：

• 1.提交工单时，用户可以选择转存，输入一个天数，然后提交成功。这时候单子需要变成转存量。
• 2.技术方案中是这么处理，对于转存的订单，通过redis设置key的失效时间（这里的时间就是转存天数换算成的秒）。
• 3.客户端通过订阅Key失效事件，判断是转存订单，然后会通过redis zset对象入队；同时，把转存队列的该工单出队，实现工单队列从转存队列转移到正式队列。
• 4.正式队列的工单系统会定时轮询去派单。

• 工单队列示例

![工单队列示例](img-blog.csdnimg.cn/20200813215…

2.排查过程

服务是基于容器构建部署，线上初步上线经过评估，仅发布了两个实例节点。我依次打开两个webshell窗口，根据我编写的代码业务逻辑排查输出的日志。

• 应用实例服务器1关键日志截图：

 

从上图截图，可以看到一次完成的工单提交操作，包括表单提交的数据，delayDays=3。但是，在正式队列入队前构建上下文对象时，expireSeconds=10800。

日志的输出的时间是：2020-08-12 15:16:03.591。

• 应用实例服务器2关键日志截图：

 

另一台服务器收到该工单（通过Redis存储并设置key失效时间）的失效事件，发生的时间2020-08-12 18:16:05.373。相当于当天该工单就失效了，转存才6个小时就失效了。

• RedisKeyExpirationListener

监听Key失效事件

@Component
@Slf4j
public class RedisKeyExpirationListener extends KeyExpirationEventMessageListener {

    final static String STORED_CACHE_KEY_PREFIX = WorkOrderCacheManager.CacheType.stored_cache.getKey();

    final static String SUSPENDED_CACHE_KEY_PREFIX = WorkOrderCacheMan