引言
在做日常mysql数据库维护过程,时长会遇到关于mysql timeout的相关报错,了解mysql的连接过程和常见的错误类型,知己知彼,可以更好去运维mysql,做到心中有数。
MySQL连接参数
和网络超时相关的参数,这里做下简单说明:
interactive_timeout
1
服务器在关闭之前等待交互式连接的超时时间,交互式客户端定义为在mysql_real_connect()中使用CLIENT_INTERACTIVE选项的客户端。像mysql客户端是交互式客户端。
wait_timeout
1
服务器关闭非交互式连接之前等待活动的秒数,在线程启动时,根据全局wait_timeout值或全局interactive_timeout值初始化会话wait_timeout值,取决于客户端类型(由mysql_real_connect()的连接选项CLIENT_INTERACTIVE定义)。像java使用的jdbc连接,php使用pdo连接等都是非交互式连接。
net_read_timeout
1
在终止读之前,从一个连接获得数据而等待的时间秒数;当服务正在从客户端读取数据时,net_read_timeout控制何时超时。例如load data local infile语句。
net_write_timeout
1
在终止写之前,等待多少秒把block写到连接,当服务正在写数据到客户端时,net_write_timeout控制何时超时
connect_timeout
1
在连接认证阶段的网络交互超时时间(ref login_connection)。
MySQL连接过程
其中
- connect_timeout 在获取连接阶段(authenticate)起作用
- interactive_timeout和wait_timeout 在连接空闲阶段(sleep)起作用
- net_read_timeout和net_write_timeout 则是在连接繁忙阶段(query)起作用。
mysql通信协议
mysql 客户端和服务端之间的通信协议是”半双工”, 在任何一个时刻,要么是由服务端向客户端发送数据,要么是由客户端向服务端发送数据,这两个动作不能同时发生。参数max_allowed_packet在做导入数据的时候,net_buffer_length在缓冲数据的时候就很重要了。connect_timeout
1
2Connect_timeout
The number of seconds that the mysqld server waits for a connect packet before responding with Bad handshake
MySQL连接一次连接需求经过6次“握手”方可成功,任意一次“握手”失败都有可能导致连接失败,前三次握手可以简单理解为TCP建立连接所必须的三次握手,MySQL无法控制,更多的受制于不TCP协议的不同实现,后面的三次握手过程超时与connect_timeout有关。
建立连接步骤:
- 客户端向DB发起TCP握手
- 三次握手成功,由DB发送HandShake信息,这个Packet里面包含了MySql的能力、加密seed等信息。
- 客户端根据HandShake包里面的加密seed对MySql登录密码进行摘要后,构造Auth认证包发送给DB。
- DB接收到客户端发过来的Auth包后会对密码摘要进行比对,从而确认是否能够登录。如果能,则发送Okay包返回。
- 客户端与DB的连接至此完毕。
net_read_timeout && net_write_timeout
当connect建立后,读取命令的流程如下:
- read_packet 通过函数my_net_read读取数据包,如果一次读不完成,则调用函数net_read_raw_loop进行循环读取,读取的超时由wait_timeout决定
1) 会先读取packet header,一个普通的packet header包含4个字节,压缩协议下则另外再加3个字节
2) 再从packet header中提取剩下的packet长度,继续从socket读取 - vio_read_buff vio封装了所有对socket的操作,当read_packet完成后,进入到vio相关的函数做封装处理,包括vio_init, vio_read_buffer,vio_read等。
- my_net_write mysql通过read_packet做过相关处理后,通过my_net_write函数将数据先拷贝到NET缓冲区,当长度大于MAX_PACKET_LENGTH(即4MB-1字节)会对Packet进行拆分成多个packet。每个Packet的头部都会留4个字节,其中:1~3字节,存储该packet的长度,第4个字节存储当前的packet的序号,每存储一次后递增net->pkt_nr。
每个Net对象有一个Buff(net->buff),即将发送的数据被拷贝到这个buffer中,当Buffer满时需要立刻发出到客户端。如果Buffer足够大,则只做memcpy操作。net->write_pos被更新到写入结束的位置偏移量 (net_write_buff)。
如果一次写入的数据被拆分成多个Packet,那么net->pkt_nr也对应的递增多次. pkt_nr的作用是在客户端解析时,防止包发送乱序。 - net_flush 在my_net_write函数中,如果net->buff不够用,已经会做网络写了,net_flush最终保证所有在buff中的数据被写到网络。
- net_write_raw_loop 当packet准备好发送后,调用函数net_write_raw_loop开始进行数据发送。
1) 在发送模式受vio->write_timeout影响(通过参数net_write_timeout控制);当该参数被设置成大于等于0时,使用非阻塞模式send数据包(MSG_DONTWAIT)
2) 若网络发送被中断(EINTR),会去尝试重传
3) 使用非阻塞模式send,每次并不保证数据全部发送完毕,因此需要循环的调用直到所有的数据都发送完毕
4) 当输出缓冲区满时,获得错误码EWOULDBLOCK/EAGAIN,则阻塞等待(vio_socket_io_wait),最大等待时间为net_write_timeout,超时则返回错误
interactive_timeout && wait_timeout
当query处理完成后,连接会进入到空闲阶段,此时受interactive_timeout和wait_timeout控制。关于interactive_timeout和wait_timeout,session和global有继承关系,可以自己测试,这里有篇文章,测试的很详细。
MySQL超时类型
Got timeout reading communication packets
连接超时
设置interactive_timeout和wait_timeout,使用mysql客户端连接,等待设置的超时时间后被mysql kill掉,在日志观察详情
准备
设置interactive_timeout和wait_timeout
观察日志
通过观察error log查看连接是否断开
其中,连接的thread_id为2885,超过10s后断开,出现日志详情1
2018-08-03T10:11:48.650754+08:00 2885 [Note] [MY-010914] [Server] Aborted connection 2885 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets).
其他
其他常见的错误,可以参考官方文档,有详情的介绍,也可根据实际测试结果来验证。
Got an error reading communication packets
客户端异常退出(数据包异常)
使用pt-kill工具监控mysql的语句,通过在mysql确认pt-kill守护进程存在,kill掉此进程,观察日志的详情
准备
- pt-kill安装
安装pt-kill工具,测试机使用ubuntu 16.04机器,直接使用以下命令:1
2wget -c https://www.percona.com/downloads/percona-toolkit/3.0.10/binary/debian/xenial/x86_64/percona-toolkit_3.0.10-1.xenial_amd64.deb
dpkg -i percona-toolkit_3.0.10-1.xenial_amd64.deb
pt-kill测试
- 运行pt-kill进程
命令:1
pt-kill --no-version-check --host localhost --port 3306 --user root --password 111111 --socket /opt/mysql/data/mysql.sock --match-host="127.0.0.1|localhost" --match-user="root" --match-db="sysbench|test" --match-command="Query" --match-state="statistics" --match-info="(?i-xsm:select)" --victim all --interval 1 --kill-query --daemonize --print --log=/tmp/pt-kill.log
- 查看pt-kill进程
- 查看mysql相关pt-kill进程
- Kill掉pt-kill进程
- 观察日志
1
22018-08-02T15:21:32.254962+08:00 62476 [Note] [MY-010914] [Server] Aborted connection 62476 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error readin
g communication packets).
网络错误
准备
使用linux自带的tc命令篡改数据包,设置网卡随机产生30%的损坏数据包,也可使用tc的其他场景,比如数据包重复等待去做各种测试,这里仅使用2种场景分别测试损坏数据包时,是否产生Got an error writing communication packets的情况
- 设置tc数据包修改: 命令,由于测试的机器包括多块网卡,这里全部设置:
1
2
3tc qdisc add dev eth0 root netem corrupt 30%
tc qdisc add dev eth1 root netem corrupt 30%
tc qdisc add dev lo root netem corrupt 30%
- ping结果查看: 通过ping查看,tc的设置已经生效,出现了损坏数据包
sysbench测试
通过在sysbench压测过程中,人工设置,模拟网络出现问题的情况,观察日志
- sysbench压测
1
/usr/local/bin/sysbench --db-driver=mysql --mysql-socket=/opt/mysql/data/mysql.sock --tables=1 --table_size=1000000 --report-interval=10 --time=3600 --mysql-port=3306 --mysql-user=root --mysql-password=111111 --mysql-db=sysbench --mysql-host=10.30.167.90 --max-requests=0 /usr/local/share/sysbench/oltp_read_write.lua --threads=4 run
压测结果:
- 观察error log
已经出现了Got an error writing communication packets相关告警信息1
2
3
42018-08-02T16:35:51.858793+08:00 65764 [Note] [MY-010914] [Server] Aborted connection 65764 to db: 'sysbench' user: 'root' host: 'localhost' (Got an error writing communication packets).
2018-08-02T16:35:51.899059+08:00 65767 [Note] [MY-010914] [Server] Aborted connection 65767 to db: 'sysbench' user: 'root' host: 'localhost' (Got an error writing communication packets).
2018-08-02T16:35:51.899260+08:00 65765 [Note] [MY-010914] [Server] Aborted connection 65765 to db: 'sysbench' user: 'root' host: 'localhost' (Got an error writing communication packets).
2018-08-02T16:35:51.899339+08:00 65766 [Note] [MY-010914] [Server] Aborted connection 65766 to db: 'sysbench' user: 'root' host: 'localhost' (Got an error writing communication packets).
php测试
通过以运行php代码的形式来访问数据,人工设置,模拟网络出现问题的情况,观察日志
- php代码运行
这里以互联网在线模拟为例子,地址:https://www.dooccn.com/php/
代码详情:1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
header('content-type:text/html;charset=utf-8');
try {
$db = new PDO('mysql:host=118.190.67.67;dbname=mysql', 'root', 'xxx');
//查询
$rows = $db->query('SELECT sleep(100)')->fetch(PDO::FETCH_ASSOC);
$rs = array();
foreach($rows as $row) {
$rs[] = $row;
}
$db = null;
} catch (PDOException $e) {
print "Error!: " . $e->getMessage() . "<br/>";
die();
}
print_r($rs);
- 观察error log
已经出现了Got an error writing communication packets相关告警信息1
2018-08-02T16:37:31.183490+08:00 66089 [Note] [MY-010914] [Server] Aborted connection 66089 to db: 'mysql' user: 'root' host: '106.14.17.222' (Got an error reading communication packets).
max_prepared_stmt_count
- max_prepared_stmt_count
此参数限制了同一时间在mysqld上所有session中prepared 语句的上限。一般做压力测试的prepare阶段可以会遇到此参数设置较小的问题,同时日志中会返回Got an error reading communication packets的错误,这里不再测试,在做压力测试时,需要将此参数设置大些。
准备
- 设置max_prepared_stmt_count
sysbench测试
运行压力测试
1
/usr/local/bin/sysbench --db-driver=mysql --mysql-socket=/opt/mysql/data/mysql.sock --tables=1 --table_size=1000000 --report-interval=10 --time=3600 --mysql-port=3306 --mysql-user=root --mysql-password=111111 --mysql-db=sysbench --mysql-host=10.30.167.90 --max-requests=0 /usr/local/share/sysbench/oltp_read_write.lua --threads=4 run
查看sysbench日志
在11.04的时候运行的压力测试
- 查看mysql log
1
2
32018-08-03T11:04:07.696809+08:00 5366 [Note] [MY-010914] [Server] Aborted connection 5366 to db: 'sysbench' user: 'root' host: 'localhost' (Got an error reading communication packets).
2018-08-03T11:04:07.696884+08:00 5365 [Note] [MY-010914] [Server] Aborted connection 5365 to db: 'sysbench' user: 'root' host: 'localhost' (Got an error reading communication packets).
2018-08-03T11:04:07.696959+08:00 5364 [Note] [MY-010914] [Server] Aborted connection 5364 to db: 'sysbench' user: 'root' host: 'localhost' (Got an error reading communication packets).
其他
其他常见的错误,可以参考官方文档,有详情的介绍,也可根据实际测试结果来验证。
Lost connection to MySQL server during query
超时connect_timeout
使用linux自带的tc命令设置网络延迟,达到测试所需要的效果
准备
- 设置tc数据包延迟:命令,由于测试的机器包括多块网卡,这里全部设置:
1
2tc qdisc add dev eth1 root netem delay 11000ms
tc qdisc add dev eth0 root netem delay 11000ms
登录连接测试
通过远程连接其他mysql服务器,查看登录效果,超过了默认connect_timeout的10s,报Lost connection to MySQL server during query错误
客户端异常退出(数据包正常)
开启2个session窗口,连接同一个mysql实例,第1个session开启查询,第2个session去kill掉第一个session
准备
- Session1开启查询
手动kill
- Session2查看processlist
- session2 手动kill session1连接
- session1查看查询
其他
其他常见的错误,可以参考官方文档,有详情的介绍,也可根据实际测试结果来验证。
MySQL server has gone away
MySQL server has gone away
设置mysql的interactive_timeout,使用mysql客户端开启一个窗口
准备
- 设置interactive_timeout的值
执行查询
- 在同一窗口内执行查询select sleep(10)
- 等待超过interactive_timeout时间后,再次执行查询
已经出现的错误日志:MySQL server has gone away
其他
其他常见的错误,可以参考官方文档,有详情的介绍,也可根据实际测试结果来验证。
参考
1 | http://mysql.taobao.org/monthly/2016/07/04/ |