MySQL|Aborted connection 日志分析

一 前言

作为运维DBA，我们经常会在数据库的err.log中查看到如下种类的报错信息:

[Warning] Aborted connection xx to db: 'db' user: 'xxx' host: 'hostname' (Got an error reading communication packets)
[Warning] Aborted connection xx to db:'unconnected' user: 'root' host: '127.0.0.1' (Got timeout reading communication
packets)
[Warning] Aborted connection 109 to db:'xxx' user: 'yy' host: '10.10.20.10' (Got an error writing communication packets)
[Warning] Got an error writing communication packets

这些日志到底是什么导致的呢？本文探讨一下 该 Warning 的成因。首先要提前说明的是MySQL 5.7 提供了新的日志输出内容控制参数 log_error_verbosity 该参数的值对应的影响如下:

1 只输出[Errors]级别的log日志 2 输出[Errors]和[Warnings]log日志信息 3 输出[Errors]+[Warnings]+[Notes]

只有该参数的值大于等于2时才会看到 Warning 信息。

二 两个参数

上述异常信息 其实和连接相关，MySQL 中有两个状态标示数据库运行过程中连接异常中断的数据统计。

造成 Aborted_connects 状态变量增加的可能原因：

client端试图访问数据库，但没有数据库的权限。 client端使用了错误的密码。 client端连接包不包含正确的信息。 获取一个连接包需要的时间超过connect_timeout秒。

造成Aborted_clients状态变量增加的可能原因：

程序退出前，客户机程序没有调用mysql_close()。 客户端睡眠时间超过了wait_timeout或interactive_timeout参数的秒数。 客户端程序在数据传输过程中突然终止。

三 测试

3.1 telnet 模拟建立连接超时

建立tcp连接但是没有发送 权限信息认证，超过 connect_timeout 十秒。

>show status like 'abort%';
+------------------+-------+
| Variable_name    | Value |
+------------------+-------+
| Aborted_clients  | 0     |
| Aborted_connects | 14    |
+------------------+-------+
2 rows in set (0.00 sec)

>show status like 'abort%';
+------------------+-------+
| Variable_name    | Value |
+------------------+-------+
| Aborted_clients  | 1     |
| Aborted_connects | 15    |
+------------------+-------+
2 rows in set (0.00 sec)

Aborted_clients 和 Aborted_connects 的数值都增加1并且记录异常到 error log

2020-10-26T23:55:00.366154+08:00 3784593 [Note] Aborted connection 3784593 to db: 'unconnected' user: 'unauthenticated' host: '10.215.20.109' (Got timeout reading communication packets)

3.2 空闲超时 20s

关于 interactive_timeout 和 wait_timeout 参数的深入解析请移步。

set global interactive_timeout=20;
Query OK, 0 rows affected (0.00 sec)

set global wait_timeout=20;
Query OK, 0 rows affected (0.00 sec)

Aborted_clients +1 ，errlog 记录

2020-10-27T22:47:12.278382+08:00 3842508 [Note] Aborted connection 3842508 to db: 'unconnected' user: 'root' host: '127.0.0.1' (Got timeout reading communication packets)

3.3 kill 连接

没有errlog ，但是 Aborted_clients 会增加

3.4 用户或者密码错误

$ mysql -uroot -h127.0.0.1 -P 3321 -pa
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES)

日志里面有 密码不对的Note提示，Aborted_connects 会增加1.

2020-10-27T23:24:19.181453+08:00 3844062 [Note] Access denied for user 'root'@'127.0.0.1' (using password: YES)

四 总结

导致MySQL error.log 出现Warning异常的主要原因

client 会话链接未正常关闭，程序没有调用mysql_close()。 空闲时间超过 wait_timeout 或 interactive_timeout 设置的秒数。 查询数据包大小超过max_allowed_packet数值，造成链接中断。 其他网络或者硬件层面的问题。比如网络连接超过 connect_timout。

如果系统中出现大量 Got timeout reading communication packets 的时候 就需要我们人为介入了，排查到底是不是网络异常导致的该错误。

参考文档

https://dev.mysql.com/doc/refman/5.7/en/communication-errors.html

https://www.percona.com/blog/2016/05/16/mysql-got-an-error-reading-communication-packet-errors/

-The End-