结论
mysqli没有处理对端(MySQL server)的断开请求。在send时,收到对端(MySQL server)的RST,会打印MySQL server has gone away。
环境
xxxx@xxxx:~$ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description: Debian GNU/Linux 8.4 (jessie)
Release: 8.4
Codename: jessie
xxxx@xxxx:~$ php --version
PHP 5.6.30 (cli) (built: Oct 27 2017 11:18:47) (DEBUG)
Copyright (c) 1997-2016 The PHP Group
Zend Engine v2.6.0, Copyright (c) 1998-2016 Zend Technologies
with Zend OPcache v7.0.6-dev, Copyright (c) 1999-2016, by Zend Technologies
MySQL server的官方解释
https://dev.mysql.com/doc/refman/5.7/en/gone-away.html
官方文档非常罗嗦,简单说来就是:
- 无效链接
1.关闭连接后仍然发起查询如超时断开、主动断开
2.fork子进程使用父进程的链接)。 - 查询太大。
- 无访问权限。
- 网络问题(防火墙等)。
都可能造成MySQL server has gone away。
而我遇到的问题属于无效链接。
抓包分析
可以看到。
No.469 是 MySQL server的tcp断开请求,apache的工作进程并没有返回FIN。
netstat的结果也证明了这一点:
tcp 0 0 0.0.0.0:3306 0.0.0.0:* LISTEN 11439/mysqld
tcp 1 0 127.0.0.1:56236 127.0.0.1:3306 CLOSE_WAIT 21523/apache2
tcp 1 0 127.0.0.1:56196 127.0.0.1:3306 CLOSE_WAIT 21466/apache2
tcp 1 0 127.0.0.1:56191 127.0.0.1:3306 CLOSE_WAIT 21523/apache2
tcp 0 0 127.0.0.1:3306 127.0.0.1:56247 FIN_WAIT2 -
tcp 0 0 127.0.0.1:3306 127.0.0.1:56236 FIN_WAIT2 -
tcp 1 0 127.0.0.1:56247 127.0.0.1:3306 CLOSE_WAIT 21466/apache2
No.2113 是 MySQL client 的 Change User 请求,值得注意的是,仍然用原端口(链接)和MySQL server通信。被MySQL server RST,触发MySQL server has gone away
开始我认为这是一个BUG,于是开始从源码中寻找答案。
源码分析
在脚本层定位到链接、报错发生在:
$this->_mysqli->real_connect
对应的c函数:
mysqli_noapi.c:mysqli_common_connect
因为链接由apache工作进程持有,mysqli拓展作为动态库载入,若apache需要对MySQL server的FIN包做出处理,mysqli 拓展必须在建立链接时,将链接ID传给apache。
但我没找到这样的逻辑。
结论是:
实现就是如此。MySQL断开链接时,mysqli对失效链接无任何处理。
mysqli在send时才能发现链接失效,若链接失败,会重连一次。
调试证实
No.2113 被RST
mysqlnd_auth.c:226,单步执行后,tcpdump抓到
15:21:20.300274 IP localhost.i.nease.net.56230 > localhost.i.nease.net.mysql: Flags [P.], seq 2540548209:2540548279, ack 3116587272, win 86, options [nop,nop,TS val 888121188 ecr 888020891], length 70
15:21:20.300305 IP localhost.i.nease.net.mysql > localhost.i.nease.net.56230: Flags [R], seq 3116587272, win 0, length 0
错误信息来源:
mysqlnd_auth.c:234
(gdb) n
234 COPY_CLIENT_ERROR(*conn->error_info, chg_user_resp->error_info);
(gdb) p conn->error_info.error
$14 = "MySQL server has gone away", '\000' <repeats 486 times>
mysqli使用失效链接时,被MySQL server RST。
重连
mysqli_nonapi.c
244 if (mysqlnd_connect(mysql->mysql, hostname, username, passwd, passwd_len, dbname, dbname_len,
(gdb) n
tcpdump 结果
15:27:33.105716 IP localhost.i.nease.net.56247 > localhost.i.nease.net.mysql: Flags [S], seq 842214159, win 43690, options [mss 65495,sackOK,TS val 888214389 ecr 0,nop,wscale 9], length 0
15:27:33.105738 IP localhost.i.nease.net.mysql > localhost.i.nease.net.56247: Flags [S.], seq 3337503184, ack 842214160, win 43690, options [mss 65495,sackOK,TS val 888214389 ecr 888214389,nop,wscale 9], length 0
15:27:33.105771 IP localhost.i.nease.net.56247 > localhost.i.nease.net.mysql: Flags [.], ack 1, win 86, options [nop,nop,TS val 888214389 ecr 888214389], length 0
15:27:33.106227 IP localhost.i.nease.net.mysql > localhost.i.nease.net.56247: Flags [P.], seq 1:79, ack 1, win 86, options [nop,nop,TS val 888214389 ecr 888214389], length 78
15:27:33.106241 IP localhost.i.nease.net.56247 > localhost.i.nease.net.mysql: Flags [.], ack 79, win 86, options [nop,nop,TS val 888214389 ecr 888214389], length 0
15:27:33.106362 IP localhost.i.nease.net.56247 > localhost.i.nease.net.mysql: Flags [P.], seq 1:122, ack 79, win 86, options [nop,nop,TS val 888214389 ecr 888214389], length 121
15:27:33.106373 IP localhost.i.nease.net.mysql > localhost.i.nease.net.56247: Flags [.], ack 122, win 86, options [nop,nop,TS val 888214389 ecr 888214389], length 0
15:27:33.106479 IP localhost.i.nease.net.mysql > localhost.i.nease.net.56247: Flags [P.], seq 79:90, ack 122, win 86, options [nop,nop,TS val 888214389 ecr 888214389], length 11
15:27:33.142634 IP localhost.i.nease.net.56247 > localhost.i.nease.net.mysql: Flags [.], ack 90, win 86, options [nop,nop,TS val 888214399 ecr 888214389], length 0
可以看到。因mysqli_common_connect在链接失效时,会重试一次。
项目使用了pconnect,大量长链接因空闲超时被断开,下次请求时,链接失效会导致gone away,因为有重连。该报错可忽略。