PHP使用Redis存储session时的一个Warning定位

1. 问题现象

系统页面刷新的时候，偶尔会报错下面的Warnning,但是不经常出现：

Warning: Unknown: Failed to write session data (redis). Please verify that the current setting of session.save_path is correct (tcp://x.x.x.x:6379?auth=yyy) in Unknown on line 0

看网络有人说是redis版本的问题、但是没有具体结论,那么本着学习的态度，自己试试看看能不能捉出这个bug.

定位问题：

1. 查看php文件是否有设置session的地方，发现没有

2. 继续检查php配置文件，发现配置了session存储到redis里面

[Session]session.save_handler = redissession.save_path = "tcp://x.x.x.x:6379?auth=yyyy"session.use_cookies = 1

1. 继续查看php Session扩展源代码，定位出错提示语在函数php_session_save_current_state中

检查session扩展文件中出错提示：

static void php_session_save_current_state(TSRMLS_D) /* {{{ */{    int ret = FAILURE;    //是否session数组    IF_SESSION_VARS() {        if (PS(mod_data) || PS(mod_user_implemented)) {            char *val;            int vallen;          //变量编码            val = php_session_encode(&vallen TSRMLS_CC);            if (val) {                //保存session数据                ret = PS(mod)->s_write(&PS(mod_data), PS(id), val, vallen TSRMLS_CC);                efree(val);            } else {                //清空session                ret = PS(mod)->s_write(&PS(mod_data), PS(id), "", 0 TSRMLS_CC);            }        }       //看出错提示语在这里        if (ret == FAILURE) {            php_error_docref(NULL TSRMLS_CC, E_WARNING, "Failed to write session data (%s). Please "                    "verify that the current setting of session.save_path "                    "is correct (%s)",                    PS(mod)->s_name,                    PS(save_path));        }    }    if (PS(mod_data) || PS(mod_user_implemented)) {        PS(mod)->s_close(&PS(mod_data) TSRMLS_CC);    }}static void php_session_flush(TSRMLS_D){    如果 (PS(session_status) == php_session_active)        session_status = none        这里调用...        php_session_save_current_state}下面两个函数调用：php_session_flush（）static PHP_FUNCTION(session_write_close){    php_session_flush(TSRMLS_C);}static PHP_FUNCTION(session_register_shutdown){}

由上面可以看到，php_session_save_current_state是在 php_session_flush中调用，即在session保存、清空等刷新写session的时候会产生。

1. 由php seesion源码没有发现什么问题，突然想到会不会是Redis本身有没有啥问题，导致的写出错。因而继续从redis里面找问题：

Redis问题定位

1. 首先查看Redis日志文件：

看到如下每5分钟会刷新一下如下log：

[16723] 04 Jul 15:15:01.987 # Server started, Redis version 2.8.9[16723] 04 Jul 15:15:01.987 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.[16723] 04 Jul 15:15:01.996 * DB loaded from disk: 0.008 seconds[16723] 04 Jul 15:15:01.996 * The server is now ready to accept connections on port 6379

怀疑这就是问题的PHP写日志失败的原因了。那么Redis为啥会5分钟重启呢？继续追查！

2. 是系统内存不够、Redis core了？

查看系统和Redis内存使用状态：

系统内存状态：

$ free -m             total       used       free     shared    buffers     cachedMem:          3516       3171        345          0        684       1680-/+ buffers/cache:        806       2709Swap:         2055        724       1330

Redis服务器占用的内存状态：

used_memory:2841648used_memory_human:2.71Mused_memory_rss:3710976used_memory_peak:2877576used_memory_peak_human:2.74Mused_memory_lua:33792mem_fragmentation_ratio:1.31mem_allocator:jemalloc-3.2.0

可以看到Redis其实内存占用非常少。redis重启原因暂且不明。

3. 定时脚本

因为重启日志5分钟一次、非常规律，因而怀疑是不是别的原因导致Redis重启,比如定时脚本。
因为本人没有root corntab权限，找老板提权，看到赫然存在着一个crontab，5分钟监控一次redis。
如下：
/5 * * * /data/scripts/check_redis.sh >/dev/null 2>&1 ##check_redis.tag.1

查看脚本内容

PORT='6379'ETH1_ADDR=`/sbin/ifconfig eth1 | awk -F ':' '/inet addr/{print $2}' | sed 's/[a-zA-Z ]//g'`retval=`nmap --system-dns -sT -p ${PORT} ${ETH1_ADDR} | grep open`if [ "${retval}X" = "X" ]; then        /sbin/service redis restart >/dev/null 2>&1fi

这是一个检查Redis端口是否提供服务的脚本，如果检查不成功，就拉起Redis。
可以看到这个脚本本来没有什么问题。

但是：通过手动执行这个命令发现：
这台机器没有安装nmap 这个命令，

所以这个脚本最后总是执行失败！然后Redis重启。

因为问题根源找到了,找运维安装相关命令，问题解决。