php mysqli MySQL server has gone away 问题分析

结论

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,因为有重连。该报错可忽略。

posted @ 2017-10-27 16:40  enjolras  阅读(1812)  评论(0编辑  收藏  举报