read error on connection的两种原因分析

摘要：最近线上模块偶现具体报错日志如下通过分析和学习之后，发现两种原因可能导致返回执行超时使用已经断开的连接下面将对这两种情况进行具体的分析。四参考和错误排查超时问题及解决

最近线上php模块偶现 read error on connection；具体报错日志如下

 Uncaught exception "RedisException" with message "read error on connection" 

通过分析和学习之后，发现两种原因可能导致 phpredis 返回 "read error on connection"：

执行超时

使用已经断开的连接

下面将对这两种情况进行具体的分析。

超时又可以分两种情况：一种是客户端设置的超时时间过短导致的；另外一种是客户端未设置超时时间，但是服务端执行时间超过了默认超时时间设置。

测试环境的 get 操作 执行耗时约 0.1ms 数量级；因此客户端设置执行超时时间为0.01ms, 测试脚本如下：

pconnect("127.0.0.1", 6390);
    if ($ret == false) {
        echo "Connect return false";
        exit;
    }
    //设置超时时间为 0.1ms
    $rds->setOption(3,0.0001);
    $rds->get("aa");
} catch (Exception $e) {
    var_dump ($e);
}

手动执行该脚本会捕获"read error on connection"异常;

客户端未设置超时时间，但是在命令执行的过程中，超时达到php设置的默认值，详见 phpredis subscribe超时问题及解决 分析

通过strace 查看执行过程可以发现发送 get aa 指令后，poll 想要拉取 POLLIN 事件的时候等待超时：

php连接redis 使用的是phpredis扩展，在phpredis源码中全文搜索 "read error on connection" 可以发现 此错误位于 phpredis/library.c 文件的 redis_sock_gets 函数，详见 phpredis ;

phpredis 的 library.c 文件的 redis_sock_gets 函数

/*
 * Processing for variant reply types (think EVAL)
 */

PHP_REDIS_API int
redis_sock_gets(RedisSock *redis_sock, char *buf, int buf_size,
                size_t *line_size)
{
    // Handle EOF
    if(-1 == redis_check_eof(redis_sock, 0)) {
        return -1;
    }

    if(php_stream_get_line(redis_sock->stream, buf, buf_size, line_size)
                           == NULL)
    {
        char *errmsg = NULL;

        if (redis_sock->port < 0) {
            spprintf(&errmsg, 0, "read error on connection to %s", ZSTR_VAL(redis_sock->host));
        } else {
            spprintf(&errmsg, 0, "read error on connection to %s:%d", ZSTR_VAL(redis_sock->host), redis_sock->port);
        }
        // Close our socket
        redis_sock_disconnect(redis_sock, 1);

        // Throw a read error exception
        REDIS_THROW_EXCEPTION(errmsg, 0);
        efree(errmsg);
        return -1;
    }

    /* We don"t need 
 */
    *line_size-=2;
    buf[*line_size]="";

    /* Success! */
    return 0;
}

附： 这个msg 看着比线上的msg 多了 host 和 port ， 是因为最近合并分支的原因，如图

从源码中可以发现如果php_stream_get_line读取stream数据为NUll的时候就会抛出read error on connection这个错误。那么什么时候php_stream_get_line会返回NULL呢， 对应于php源码的php-src/main/streams/streams.c 文件 ， 详见php-src;

/* If buf == NULL, the buffer will be allocated automatically and will be of an
 * appropriate length to hold the line, regardless of the line length, memory
 * permitting */
PHPAPI char *_php_stream_get_line(php_stream *stream, char *buf, size_t maxlen,
        size_t *returned_len)
{
    size_t avail = 0;
    size_t current_buf_size = 0;
    size_t total_copied = 0;
    int grow_mode = 0;
    char *bufstart = buf;

    if (buf == NULL) {
        grow_mode = 1;
    } else if (maxlen == 0) {
        return NULL;
    }

    /*
     * If the underlying stream operations block when no new data is readable,
     * we need to take extra precautions.
     *
     * If there is buffered data available, we check for a EOL. If it exists,
     * we pass the data immediately back to the caller. This saves a call
     * to the read implementation and will not block where blocking
     * is not necessary at all.
     *
     * If the stream buffer contains more data than the caller requested,
     * we can also avoid that costly step and simply return that data.
     */

    for (;;) {
        avail = stream->writepos - stream->readpos;

        if (avail > 0) {
            size_t cpysz = 0;
            char *readptr;
            const char *eol;
            int done = 0;

            readptr = (char*)stream->readbuf + stream->readpos;
            eol = php_stream_locate_eol(stream, NULL);

            if (eol) {
                cpysz = eol - readptr + 1;
                done = 1;
            } else {
                cpysz = avail;
            }

            if (grow_mode) {
                /* allow room for a NUL. If this realloc is really a realloc
                 * (ie: second time around), we get an extra byte. In most
                 * cases, with the default chunk size of 8K, we will only
                 * incur that overhead once.  When people have lines longer
                 * than 8K, we waste 1 byte per additional 8K or so.
                 * That seems acceptable to me, to avoid making this code
                 * hard to follow */
                bufstart = erealloc(bufstart, current_buf_size + cpysz + 1);
                current_buf_size += cpysz + 1;
                buf = bufstart + total_copied;
            } else {
                if (cpysz >= maxlen - 1) {
                    cpysz = maxlen - 1;
                    done = 1;
                }
            }

            memcpy(buf, readptr, cpysz);

            stream->position += cpysz;
            stream->readpos += cpysz;
            buf += cpysz;
            maxlen -= cpysz;
            total_copied += cpysz;

            if (done) {
                break;
            }
        } else if (stream->eof) {
            break;
        } else {
            /* XXX: Should be fine to always read chunk_size */
            size_t toread;

            if (grow_mode) {
                toread = stream->chunk_size;
            } else {
                toread = maxlen - 1;
                if (toread > stream->chunk_size) {
                    toread = stream->chunk_size;
                }
            }

            php_stream_fill_read_buffer(stream, toread);

            if (stream->writepos - stream->readpos == 0) {
                break;
            }
        }
    }

    if (total_copied == 0) {
        if (grow_mode) {
            assert(bufstart == NULL);
        }
        return NULL;
    }

    buf[0] = "";
    if (returned_len) {
        *returned_len = total_copied;
    }

    return bufstart;
}

从 php_stream_get_line方法中可以看出 只有 bufstart=NULL的时候才会返回NULL，bufstart=NULL说明并未在buf缓冲和stream中接收到任何数据，包括终止符。

客户端设置合理的超时时间，有两种方式：

ini_set("default_socket_timeout", -1);

$redis->setOption(Redis::OPT_READ_TIMEOUT, -1);

注： -1均表示不超时，也可以将超时设置为自己希望的时间， 前面复现时就是设为为0.01ms

使用已经断开的连接也有可能导致 "read error on connection"， 这里需要区分 "Connection closed" 和 "Connection lost"。

测试脚本如下，客户端主动关闭连接，但是下文接着使用该断开的链接，然后抛出异常返回 connection closed

pconnect("127.0.0.1", 6390);
    if ($ret == false) {
        echo "Connect return false";
        exit;
    }

    $rds->close();
    
    var_dump($rds->get("aa"));
} catch (Exception $e) {
    var_dump ($e);
}

测试结果如下：

参考Work around PHP bug of liveness checking 编写测试脚本 test.php 如下，连接上redis之后，在执行命令前kill redis 进程：

pconnect("127.0.0.1", 6390);
    if ($ret == false) {
        echo "Connect return false";
        exit;
    }

    echo "Press any key to continue ...";
    fgetc(STDIN);
    var_dump($rds->get("aa"));
} catch (Exception $e) {
    var_dump ($e);
}

如果

执行步骤如下

终端执行 php test.php 脚本

另开一个终端 kill redis 进程

第一个终端任意输入、回车

此时会出现 "Connection lost"

连接上redis之后，不断执行命令的过程中，如果连接断开，会返回 read error on connection。测试脚本如下：

pconnect("127.0.0.1", 6390);
    if ($ret == false) {
        echo "Connect return false";
        exit;
    }

    while(1){
       $rds->get("aa");
    }
    
} catch (Exception $e) {
    var_dump ($e);
}

如果

执行步骤如下

终端执行 php test.php 脚本

另开一个终端 kill redis 进程

此时抛出异常：

或者新打开终端连接上redis服务端，执行client kill ，如下:

正在执行的php脚本同样会捕获该异常read error on connection。

在cli 模式下， 通过php通过 pconnect 连接redis服务端，虽然业务代码，显示调用close, 但是实际上该连接并未断开，fpm 会维护到redis 的连接，下个请求再次执行pconnect 的时候并不会真正请求redis 建立连接。这样同样会带来一个问题，假如这个连接已经断开了，下个请求可能直接使用上个断开的连接，对此，phpredis 在其源码也有注释，详见php-src

因此php-fpm reuse 一个断开的连接可能导致此类错误。

此种情况最简单的解决方案就是改长链接为短链接了

网上有很多关于 执行超时及其解决方案的分析，但是对于连接断开重新使用的分析较少，故此分析之，一方面用作记录，另一方面希望能够给面临同样问题的小伙伴一点帮助。

[1] redis read error on connection和Redis server went away错误排查

[2] Work around PHP bug of liveness checking

[3] phpredis subscribe超时问题及解决

[4] php-src

[5] phpredis