php 获取数据慢的脚本一例

背景：

  今天遇到一例php连接redis获取value时间波动的问题，在几百毫秒到几秒钟不等，对于使用了redis来说这个时间确实比较久

排查：

1，检查redis各项监控项没有明显的异常（qps，吞吐量，cpu）
2，检查ecs自身的负载，内网带宽是否存在突发的情况（一般类比其他时间段的流量峰值看看能高出多少）
3，长ping测试网络是否有波动

php输出毫秒级时间尝试获取慢在哪里？

<?php

$host = "*****.redis.rds.aliyuncs.com";
$port = 6379;
$user = "*****";
$pwd = "*****";
$redis = new Redis();
list($s1, $s2) = explode(' ', microtime());
echo "Start_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";
if ($redis->connect($host, $port) == false) {
    die($redis->getLastError());
}
list($s1, $s2) = explode(' ', microtime());
echo "Conn_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";
if ($redis->auth($pwd) == false) {
    die($redis->getLastError());
}
list($s1, $s2) = explode(' ', microtime());
echo "Auth_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";
if ($redis->set("foo", "bar") == false) {
    die($redis->getLastError());
}
list($s1, $s2) = explode(' ', microtime());
echo "Set_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";
$value = $redis->get("foo");
list($s1, $s2) = explode(' ', microtime());
echo "Get_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";
echo "The keys value is:".$value."\n";

?>

脚本大意：
参数设置相关：

$host = "*****.redis.rds.aliyuncs.com";
$port = 6379;
$user = "*****";
$pwd = "*****";
$redis = new Redis();

输出第一个执行时间（Start_time:脚本开始时间，前面的变量设置这里不计了）

list($s1, $s2) = explode(' ', microtime());
echo "Start_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";

输出第二个执行时间（Conn_time:第二个可以理解为连接时间，如果dns解析慢，或者tcp三次握手建联慢，都会体现在这里）

if ($redis->connect($host, $port) == false) {
    die($redis->getLastError());
}
list($s1, $s2) = explode(' ', microtime());
echo "Conn_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";

输出第三个执行时间（Auth_time:密码验证的时间消耗）

if ($redis->auth($pwd) == false) {
    die($redis->getLastError());
}
list($s1, $s2) = explode(' ', microtime());
echo "Auth_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";

输出第四个执行时间（Set_time:set一个key value的时间）

if ($redis->set("foo", "bar") == false) {
    die($redis->getLastError());
}
list($s1, $s2) = explode(' ', microtime());
echo "Set_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";

输出第五个执行时间（Get_time:这个时间用来计算get前面设置的key的时间，脚本最后输出对应的key）

$value = $redis->get("foo");
list($s1, $s2) = explode(' ', microtime());
echo "Get_time:" . date("Y-m-d H:i:s", $s2) . "." . (float) sprintf('%.0f', $s1 * 1000) . "\n";
echo "The keys value is:".$value."\n";

循环运行这个脚本

for i in {1..500};do php ali-redis-test.php;sleep 1s;done >>time.txt

这个是linux命令行直接运行的，运行500次这个php脚本，每次间隔1秒钟，>>time.txt代表将记录写入这个文件

脚本运行截图

配合抓包工具进行抓包，基本可以定位到慢在哪个环节，然后具体问题再具体分析

tcpdump -i eth0(内网网卡) host  r-******.redis.rds.aliyuncs.com and port 6379 -w 1.cap