MySQL令人头疼的Aborted告警案例分析

432232

MySQL关于aborted告警日志的分析实战

Part1:写在最前

在MySQL的error log中，我们会经常性看到一些各类的Abortedconnection错误，本文中会针对这类错误进行一个初步分析，并了解一个问题产生后的基本排查思路和方法。掌握这种方法是至关重要的，而不是出现问题了，去猜，去试。数据库出现问题的时候需要DBA在短时间内快速解决问题，因此一个好与坏的DBA，区别也在于此。



Part2:种类

1 2 3 4 5 6

[Warning] Aborted connection 305628 to db: 'db' user: 'dbuser' host: 'hostname' (Got an error reading communication packets) [Warning] Aborted connection 81 to db:'unconnected' user: 'root' host: '127.0.0.1' (Got timeout reading communication packets) [Warning] Aborted connection 109 to db:'helei1' user: 'sys_admin' host: '192.168.1.1' (Got an error writing communication packets) [Warning] Access denied for user 'root'@'127.0.0.1' (using password: YES) [Warning] Got an error writing communication packets

Part3:重点参数分析

wait_timeout

Command-Line Format	--wait-timeout=#
System Variable	Name	wait_timeout
	Variable Scope	Global, Session
	Dynamic Variable	Yes
Permitted Values (Windows)	Type	integer
	Default	28800
	Min Value	1
	Max Value	2147483
Permitted Values (Other)	Type	integer
	Default	28800
	Min Value	1
	Max Value	31536000

这个参数指的是数据库系统在关闭它之前，服务器等待非交互式连接上的活动的秒数。

interactive_timeout

Command-Line Format	--interactive-timeout=#
System Variable	Name	interactive_timeout
	Variable Scope	Global, Session
	Dynamic Variable	Yes
Permitted Values	Type	integer
	Default	28800
	Min Value	1

这个参数指的是在关闭交互式连接之前，服务器等待活动的秒数

Warning:警告这两个参数建议一起调节，能够避免一些坑。

本文的两个参数值采用的是默认值

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16

mysql> show global variables like '%timeout%'; +----------------------------+----------+ | Variable_name              | Value    | +----------------------------+----------+ | connect_timeout            | 10       | | delayed_insert_timeout     | 300      | | innodb_lock_wait_timeout   | 50       | | innodb_rollback_on_timeout | OFF      | |interactive_timeout        | 28800    | | lock_wait_timeout          | 31536000 | | net_read_timeout           | 30       | | net_write_timeout          | 60       | | slave_net_timeout          | 3600     | |wait_timeout               | 28800    | +----------------------------+----------+ 10 rows in set (0.01 sec)

另外在数据库中，我们重点关注下这两个参数，看看什么情况下Aborted_clients会提升，什么情况下Aborted_connects 会提升

1 2 3 4 5 6 7 8

mysql>show global status like 'aborted%'; +------------------+-------+ |Variable_name    | Value | +------------------+-------+ |Aborted_clients  | 19    | |Aborted_connects | 0     | +------------------+-------+ 2 rows inset (0.00 sec)

Part4:案例1

这里我故意输入错误的密码5次，来看下数据库的error log和Aborted的哪个参数记载了这一问题

1 2 3 4 5 6 7 8 9 10

[iyunv@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1 ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES) [iyunv@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1 ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES) [iyunv@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1 ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES) [iyunv@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1 ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES) [iyunv@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1 ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES)

可以看出，这里的Aborted_connects 记录了密码错误的这一问题

1 2 3 4 5 6 7 8

mysql>show global status like 'aborted%'; +------------------+-------+ |Variable_name    | Value | +------------------+-------+ |Aborted_clients  | 19    | |Aborted_connects | 5     | +------------------+-------+ 2 rows inset (0.00 sec)

error log中，也记载了这类密码输错的信息

1 2 3 4 5

[Warning] Access denied for user'root'@'127.0.0.1' (using password: YES) [Warning] Access denied for user 'root'@'127.0.0.1' (using password:YES) [Warning] Access denied for user 'root'@'127.0.0.1' (using password:YES) [Warning] Access denied for user 'root'@'127.0.0.1' (using password:YES) [Warning] Access denied for user 'root'@'127.0.0.1' (using password:YES)

Part5:案例2

接下来我们看下文章第三节提到的两个重点参数对数据库连接的行为影响

这里我们将这两个参数均配置为10秒

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15

mysql>set global wait_timeout=10; Query OK,0 rows affected (0.00 sec)    mysql>set global interactive_timeout=10; Query OK,0 rows affected (0.00 sec) mysql>show processlist; ERROR 2006 (HY000): MySQL server has gone away No connection. Trying to reconnect... Connection id: 79 Current database: *** NONE ***    +----+------+-----------------+------+---------+------+-------+------------------+ | Id |User | Host            | db   | Command | Time | State | Info             | +----+------+-----------------+------+---------+------+-------+------------------+ | 79 |root | 127.0.0.1:42016 | NULL | Query  |    0 | NULL  | show processlist | +----+------+-----------------+------+---------+------+-------+------------------+ 1 row in set (0.00 sec)

这里三次操作，可以看到clients数上升，这是由于timeout参数控制的，已经连接上数据的连接被杀掉。

1 2 3 4 5 6 7 8 9 10 11

mysql>show global status like 'aborted%'; ERROR 2006 (HY000): MySQL server has gone away No connection. Trying to reconnect... Connection id:    81 Current database: *** NONE ***    +------------------+-------+ |Variable_name    | Value | +------------------+-------+ |Aborted_clients  | 22    | |Aborted_connects | 5     | +------------------+-------+ 2 rows in set (0.01 sec)

error log中记载的是

1 2 3

[Warning] Aborted connection 81 to db: 'unconnected' user: 'root' host: '127.0.0.1' (Got timeout reading communication packets) [Warning] Aborted connection 78 to db: 'unconnected' user: 'root' host: '127.0.0.1' (Got timeout reading communication packets) [Warning] Aborted connection 79 to db: 'unconnected' user: 'root' host: '127.0.0.1' (Got timeout reading communication packets)

Part6:案例3

在这个案例中我们看下最大连接数对数据库连接的行为影响

1 2 3 4 5 6 7 8 9 10 11 12

mysql>show global variables like 'max_conn%'; +--------------------+-------+ |Variable_name      | Value | +--------------------+-------+ |max_connect_errors | 1000  | |max_connections    | 1024  | +--------------------+-------+ 2 rows in set (0.00 sec)       mysql>set global max_connections=2; Query OK,0 rows affected (0.00 sec)

这里看到爆出了连接数过多的问题

1 2	[iyunv@HE3~]# mysql -uroot -pMANAGER -h127.0.0.1 ERROR 1040 (HY000): Too many connections

而错误日志没有任何记录

Part7:案例4

第三方工具navicat select结果没有出来的时候选择停止则出现

clients上涨

1 2 3 4 5 6 7 8

mysql>show global status like 'aborted%'; +------------------+-------+ |Variable_name    | Value | +------------------+-------+ |Aborted_clients  | 28    | |Aborted_connects | 10    | +------------------+-------+ 2 rows in set (0.00 sec)

error log日志记录

1	170626 16:26:56 [Warning] Aborted connection 109 to db: 'helei1' user: 'sys_admin' host: '192.168.1.1' (Got an error writing communication packets)

Part8:原因总结

• 在MySQL中sleep状态数百秒的而且经常重复连接是应用程序在工作后没有关闭连接的症状之一，而是依靠数据库wait_timeout来关闭它们。强烈建议在操作结束时更改应用程序逻辑以正确关闭连接；
• 检查以确保max_allowed_packet的值足够高，并且客户端没有收到“数据包太大”消息。 这种情况他会中止连接，而不正确关闭它；
• 另一种可能性是TIME_WAIT。建议您确认连接被妥善管理并且是在应用端正常关闭；
• 确保事务正确提交（开始和提交），以便一旦应用程序“完成”连接，它将处于“clean”的状态；
• 您应该确保客户端应用程序不中止连接。 例如，如果PHP的选项max_execution_time设置为5秒，增加connect_timeout是没用的，因为PHP会杀死脚本。 其他编程语言和环境也有类似的选项；
• 连接延迟的另一个原因是DNS问题。 检查是否启用了skip-name-resolve，检查主机根据其IP地址而不是其主机名进行身份验证；
• 尝试增加MySQL的net_read_timeout和net_write_timeout值，看看是否减少了错误的数量。