背景描述
公司购买了阿里云的集群版云Redis, 在项目中使用TP5中的队列插件(think-queue),驱动是使用Redis。在运行中发现一个非常诡异的问题,每次当执行一次消费脚本报错时,接下来框架会疯狂抛出NOAUTH Authentication required.的异常。
一开始以为是阿里云Redis白名单的问题,但是加了IP也还是同样有问题,这个问题基本是因为没有进行auth认证,但是这个框架底层的代码怎么可能会没有呢?而且只是执行队列才会有问题。而正常连接Redis的命令是没有问题的。百度基本没有任何结果
每次发生异常后,因为用的queue:work模式,系统会疯狂执行并抛出异常,导致服务器日志撑爆硬盘,十分苦恼,于是开启了对这个问题的苦命追溯
解决过程
看错误堆栈
打印出来的堆栈如下
看框架代码
通过堆栈找到对应行数,开始debug定位问题
通过debug发现问题在于执行redis的exec命令时,卡住不动,等一会就报NOAUTH Authentication required了
但为什么堆栈信息显示的是$this->redis->unwatch();这个语句抛异常,而我们实验的时候发现是卡在exec就不动了呢?
带着疑问,我们把底层这个消费的逻辑全扣了出来,单独拎出来执行,大概代码如下
通过阅读框架代码,大致了解了think-queue的具体pop流程,当执行消费脚本异常后,对应的任务会被重置到queues:*:reserved的有序集合中
但是,当我们运行这段代码的时候,发现抛出的异常并不是NOAUTH Authentication required
而是报了connection close , 连接被关闭
再细看的时候才知道,原来是因为外层加了异常捕捉,当上面这个connection close异常被捕捉后,程序还会接着往下走,就走到了unwacth上了
当队列任务异常后,到下一次执行queue:work时,会执行上述图片的流程,主要如下:
1. 开启watch,监听key,防止被修改
2. 开启事务(multi)
3. 然后执行命令(zRemRangeByScore删除queues:*:reserved, 然后rPush重推到正常的list中)
4. 然后调用exec方法
5. 抛Connection closed被捕捉, 程序继续运行
6. 进行事务回滚(discard)
7. unwatch
我们大概可以猜测到为啥框架会抛NOAUTH Authentication required了,因为前面一开始执行消费的时候,确实在构造函数已经将redis连接并进行了密码认证:
但当我们程序执行到exec的时候,抛出了connection close,即连接已关闭,说明前面和redis建立的连接已断开,而此时被捕捉后程序继续,还在同一个句柄中,直接执行unwatch肯定就抛出了NOAUTH Authentication required
抓包
为了确认我们的判断是否准确,我们使用tcpdump抓包分析,通过抓包可以发现,我们执行一次脚本,实际开了两个端口来连接redis,第一个端口有进行密码认证,但第二个就没有了,直接一个unwacth
可以看到这个包里上面A端口连过来是正常的,发了AUTH,下面B这个端口连过来,发了一个unwatch,没有认证
至此,问题已经非常明确了,框架抛出NOAUTH Authentication required 只是一个误导我们的幌子,真正问题是出在了执行exec上
结果
那么为什么执行exec会等待一段时间后连接超时被关闭呢,我们咨询了阿里官方技术,通过排查,找到问题点出在于我们购买的集群版云Redis
官方回复:因为集群版设置了很多个slot,当两个key不在同一个slot下,但是而由于异常key一直存在不被删除,所以问题一直存在。由于集群版的命令导致的,这里报错后如果没有抛出错误的话也不会返回结果。而主从版不会抛出错误,就不会有问题
最后通过服务更换为主从版的配置,问题解决