背景:
今天遇到一例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