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

背景

有三个 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 的不一致。但我总觉得难以置信,因此有意忽略了。没想到,这不起眼的细节,正是解开问题的关键钥匙 ! 可见,细节不可忽视啊 !


小结

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

posted @ 2019-08-10 12:33  琴水玉  阅读(537)  评论(0编辑  收藏  举报