最近,开发周期长达三个月的“预售升级”项目进入了测试阶段。

QA在测试的时候遇到订单付款成功,但是订单列表中订单状态仍然显示为“待支付”的现象,这个bug不必现。(╮(╯▽╰)╭,最讨厌这种奇葩的bug了)
排查交易系统日志,发现支付系统发给交易系统的回调一直返回失败,证明QA大姐确实是支付成功了。手动给交易系统发送支付成功请求,并在关键地方输出日志,发现是在修改订单状态前“获取锁”的操作失败了。
查看交易系统请求redis的日志,发现修改订单状态前获取锁的操作一直返回失败。
我启动我本机上redis,输入加锁命令,发现执行是成功的,那为什么qalab的redis会一直提示失败呢?
首先想到的是可能qalab上的redis版本比较老,而RedisLocker:16012210303398这个key比较特殊,触发了某个bug。
我查看了qalab上交易系统中redis的配置地址,在rdlab上开启redis-cli连接到qalab的redis,执行订单加锁操作:

1
2
> setnx RedisLocker:16012210303398 1
> (Error) invalid argument(s)

执行info system命令,想查看一下redis的版本信息,发现redis代理根本不支持这个操作,应该是被禁用了。
登陆到qalab的redis机上,直连到一个reids实例,再执行setnx RedisLocker:16012210303398 1,发现执行时成功的。连接到redis代理上,再执行上述命令,还是一直提示失败。到这里,我将问题定位到了redis使用的代理–twemproxy上。
这时候我想查看twemproxy的日志,发现运维把日志输出关掉了,好吧,虽然只是个测试环境的redis,也不用做的这么绝吧,连日志都输出。。。。。。。
没办法,求助于google,最后在twemproxy的github issue里发现了一些线索,有个人跟我遇到了相同的问题,最后发现是有一个redis实例已经没有可用内存了,导致命令执行失败。
死马当活马医,查看twemproxy的配置文件,然后直连到每一个redis实例上,执行set a 1操作,其中一个实例报了以下错误:

1
(error) OOM command not allowed when used memory > 'maxmemory'.

也就是说,这个实例已经没有可用内存了。在这个实例上执行flushall操作,清除所有的缓存(其实直接重启该redis实例更快一点)。

给交易系统发送支付成功通知,然后观察交易系统的redis日志,发现获取锁操作已经成功,并且订单的状态已经更新为“支付成功”,至此问题解决。

总结:导致订单加锁失败的原因是有一个redis实例没有可用内存了,而RedisLocker:16012210303398这个key又恰好被twemproxy hash到了这个实例上。twemproxy的错误信息提示不完整,对一些比较重大的错误直接返回”DEFAULT ERROR”,这是比较坑的一个地方。