详解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.

定位问题：

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

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

[session]
session.save_handler = redis
session.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的时候会产生。

由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   cached
mem:     3516    3171    345     0    684    1680
-/+ buffers/cache:    806    2709
swap:     2055    724    1330

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

used_memory:2841648
used_memory_human:2.71m
used_memory_rss:3710976
used_memory_peak:2877576
used_memory_peak_human:2.74m
used_memory_lua:33792
mem_fragmentation_ratio:1.31
mem_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>&1
fi

这是一个检查redis端口是否提供服务的脚本，如果检查不成功，就拉起redis。

可以看到这个脚本本来没有什么问题。

但是：通过手动执行这个命令发现：

这台机器没有安装nmap 这个命令，

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

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

以上就是本文的全部内容，希望对大家的学习有所帮助，也希望大家多多支持。