奇怪之事总有缘由：订单状态对比不一致问题排查

背景
排查
细节
小结

背景

有三个 ES 索引: trade_state, trade_buyer, trade_seller ，各自同时监听 trade_order 消息，通过几乎一样的处理逻辑，更新索引里的订单数据。 又一个索引对比任务，会在订单消息延迟 10 分钟后将该条消息重新放入，去比较这三个索引的订单状态数据。 发现少数订单的 trade_buyer 在比较的时候总是状态有些滞后，亲自去查的时候，状态又是对的，甚是奇怪。

由于数据对比不一致任务能够及早发现问题和发出警告，而这个似乎属于“误报军情”，因此甚为干扰。如果不是问题，需要找出其中的原因并消除它。

排查

通过日志发现 ： 假设时刻 T 订单状态更新为 state = 3，时刻 T+20s 更新为 state = 6， 那么时刻 T+10min ，对比查询到的 trade_buyer 的订单状态依然是 state = 3。怕是有什么环节有梗，我打出了对比查询时的 trade_buyer 索引里的所有数据， state = 3 !

查看 trade_buyer 的写入日志，明明在时刻 T+20s 已经成功写入 state = 6 的日志啊，应该覆写了 state = 3 的数据才对，怎么会又出现 state = 3 ？ ES 同学怀疑是不是 state = 6 的订单数据又被覆写了。 然而，订单状态更新是有严格递增的版本号更新控制的，不会从 state = 6 倒退到 state = 3（除非重新强制更新 DB 里的订单状态，但线上是不会有这种情况的）；而且，在 T+20s - T+10min 时刻之间，并没有 trade_buyer state = 3 的写入日志，这个 state = 3 究竟是从哪里来的 ？ 真令人百思不得其解。

继续仔细阅读日志内容，突然发现，查询时的 trade_buyer 的 buyer_id 与写入时的 buyer_id 不一样。不会吧 ？ 于是我根据这两个不同的 buyer_id 去 trade_buyer 索引里搜索这个订单， 竟然两个都有 ！ 其中必有蹊跷。 于是，我去咨询为什么订单的 buyer_id 会变化，确实有这样的下单场景。

订单的 buyer_id 会变化，就可以讲通了： trade_buyer 是根据 buyer_id 分片的，根据不同的 buyer_id 及订单号，查到的是不同的两条订单数据。 假设在 T 时刻状态更新为 state = 3 , buyer_id = x , 而在 T+20s 时刻，buyer_id 已经变为了 y ，那么， T+20s 更新的是 buyer_id = y 的那条订单数据，而不是 buyer_id = x 的那条，也就是： buyer_id = y && state = 6, buyer_id = x && state = 3。 在 T+10min 延迟后的那条消息与 T 的消息是一样的， buyer_id = x ，这样，在 T+10min 进行对比查询时拿到的是 buyer_id = x 的那条数据，也就是未更新的脏数据。真相大白 ！

解决方法也比较简单：在对比查询时，取最新的 buyer_id 而不是原来的那条消息里的 buyer_id 。

细节

其实，对比程序也报告了 buyer_id 的不一致。但我总觉得难以置信，因此有意忽略了。没想到，这不起眼的细节，正是解开问题的关键钥匙 ！ 可见，细节不可忽视啊 ！

小结

经此一事，我明白了：奇怪之事必有缘由 ！ 如果发现了难以置信的事情，也许已经离真相很近了。再走近一步步。 此外，不可放过不起眼的细节。

作者：@琴水玉

转载请注明出处：https://www.cnblogs.com/lovesqcc/p/11331168.html

微信扫一扫下面的二维码，关注我的公众号 编程大观园 :)