redis 获取不到_记一次PHP偶现获取不到Redis数据排查过程

李乐

问题描述

3月25号早晨8点左右线上回归时，发现getTestInfos接口部分请求返回空数据。kibana查询异常请求日志，输入参数正常；梳理接口业务逻辑，是根据输入参数从Redis查询数据返回空导致。

进一步确认：1)Redis查询数据时未抛异常；2)Redis中确实存在该数据；3)只有偶尔部分请求无法从Redis获取数据。

10点25左右，重启业务进程与confd，恢复正常。

两个疑问：1)为什么部分请求会获取不到Redis的数据；2)为什么重启服务可以恢复

现状梳理

已知：服务并不是直连Redis，中间经过代理Twemproxy转发(简称tw)，tw后端存在多个Redis实例，tw通过key-hash将请求分发到具体的Redis实例。架构如下：

etcd作为注册中心，tw将自身信息ip:port:weight注册到etcd；业务机器都部署有confd进程，从etcd拉取tw配置，并同步配置到业务进程。

进一步了解：24号晚11点14分，一台tw实例曾出现"故障"，并在2分钟左右恢复。kibana查询日志验证，晚11点14分访问Redis出现短暂的异常"read error on connection"，后续再没有捕获到任何异常。

查看confd日志，晚11点14分(剔除一台tw)，晚11点16分(tw恢复)，早10点25分(confd重启)，拉取tw配置正确，切同步配置到业务进程配置文件正确，如下：

DEBUG Got the following map from store xxxx

DEBUG Target config /home/www/xxxx/conf/redis.php in sync

等等，上面说重启业务进程与confd恢复正常，业务进程为什么需要重启？原来，业务服务并不是运行在php-fpm模式下，是基于Swoole的，常驻进程。那么业务进程是如何感知到配置文件的变化并重新加载的。查看confd模板配置：

[template]

src="xxxx/config.tmpl"

dest="/home/www/xxxx/conf/redis.php"

keys=[

"xxxx",

]

check_cmd="/usr/local/php7/bin/php -l { {.src}}"

reload_com="/usr/local/php7/bin/php /home/www/xxxx/daemon/baseserver/start.php kill && /usr/local/php7/bin/php /home/www/xxxx/daemon/baseserver/start.php start"

原来业务进程是想通过confd提供的"reload_cmd"实现的(配置改变时，重启命令)，只是书写错误导致业务进程没有重启。

另外，业务代码中与tw是通过长连接通信的。

有点眉目了，tw故障以及恢复时，业务进程没有重启，从而没有成功更新配置以及重新连接tw，导致业务进程与这台tw的连接是异常的，因此无法获取数据。

进一步思考，如果tw是挂掉并重启，那业务进程之前与tw建立的连接全部异常(如果没有重连机制)；而我们只有2个tw实例，并且请求是平均分摊到2个tw实例，那么理论上应该有大概50%的请求无法无法获取数据。kibana统计异常请求与正常请求比例，只有2%左右。

经咨询，原来晚11点14分，tw是由于所在机器网络线路故障，才导致的短暂失联，tw进程并没有重启。

猜测：在tw失联期间，业务进程执行查询请求，phpredis扩展由于连接异常导致读写数据错误，并抛出异常"read error on connection"；而如果此时同时标记该连接异常，且后续没有重连机制的话，那么这些那么这些连接上的请求将全部失败。

上面说过，业务服务是基于Swoole构建的，master-manager-work进程模式，work进程真正的负责处理请求，每个work进程与每个tw进程建