reading communication packets

 

在使用mysql5.7的时候，发现了不少在mysql5.6上不曾见过的日志，级别为note, 最常见的note日志以下三种，下面我们来逐个解释。

第一种，Aborted connection . 如上图，信息如下：

2020-08-17T14:44:24.102542Z 59 [Note] Aborted connection 59 to db: ‘unconnected’ user: ‘mha’ host: ‘10.xx.xx.xx’ (Got an error reading communication packets)

2020-08-17T14:44:31.273897Z 61 [Note] Aborted connection 61 to db: ‘unconnected’ user: ‘mha’ host: ‘10.xx.xx.xx(Got an error reading communication packets)

2020-08-17T14:44:31.273897Z 61 [Note] Aborted connection 61 to db: ‘unconnected’ user: ‘mha’ host: ‘10.xx.xx.xx(Got an error reading communication packets)

 

2020-08-17T14:44:31.273897Z 61 [Note] Aborted connection 61 to db: ‘unconnected’ user: ‘mha’ host: ‘10.xx.xx.xx(Got  timeout  reading communication packets)

 

上面两个是连接中断的错误信息，原因不一样，

Got an error reading communication packets  的原因是因为网络等原因导致。

Got  timeout  reading communication packets 这个错误的原因是会话的idle时间达到了数据库指定的timeout时间。

 

 

关于Aborted connection告警日志的分析

2020-05-19阅读 3470

 

前言：

有时候，连接MySQL的会话经常会异常退出，错误日志里会看到"Got an error reading communication packets"类型的告警。本篇文章我们一起来讨论下该错误可能的原因以及如何来规避。

1.状态变量Aborted_clients和Aborted_connects

首先我们来了解下Aborted_clients和Aborted_connects这两个状态变量的含义，当出现会话异常退出时，这两个状态值会有变化。根据官方文档描述，总结如下：

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

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

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

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

简单来说即：数据库会话未能正常连接到数据库，会造成Aborted_connects变量增加。数据库会话已正常连接到数据库但未能正常退出，会造成Aborted_clients变量增加。

2.Got an error reading communication packets原因分析

哪种情况会导致error log中出现“Aborted connection xxxx to db: 'db' user: 'dbuser' host: 'hostname' (Got an error reading communication packets)”类似告警呢？

下面我们根据上面可能的原因来做下具体测试。每次测试要注意状态变量Aborted_clients和Aborted_connects的变化及错误日志记录。

• 测试一：错误密码，错误用户

1.测试前查看状态变量值:

mysql> show global status like 'abort%';

+------------------+-------+| Variable_name    | Value |+------------------+-------+| Aborted_clients  | 0     |
| Aborted_connects | 0     |+------------------+-------+
2.测试过程# mysql -uroot -pwrongpassmysql: [Warning] Using a password on the command line interface can be insecure.ERROR 1045 (28000):
 Access denied for user 'root'@'localhost' (using password: YES)# mysql -uroot1 -pwrongpassmysql:
 [Warning] Using a password on the command line interface can be insecure.ERROR 1045 (28000): 
Access denied for user 'root1'@'localhost' (using password: YES)

 

3.查看状态变化及错误日志:

mysql> show global status like 'abort%';

+------------------+-------+| Variable_name    | Value |+------------------+-------+| 
Aborted_clients  | 0     || Aborted_connects | 2     |+------------------+-------+
错误日志记录：2020-03-16T17:58:35.318819+08:00 6 [Note] 
Access denied for user 'root'@'localhost' (using password: YES)

2020-03-16T17:59:04.153753+08:00 7 [Note] Access denied for user 'root1'@'localhost' (using password: YES)
结果：Aborted_connects有增加 error log无Aborted connection相关记录

 

• 测试二：睡眠时间超时或手动杀会话

1.测试前查看状态变量值:

mysql> show global status like 'abort%';

+------------------+-------+| Variable_name    | Value |+------------------+-------+| 
Aborted_clients  | 0     || Aborted_connects | 2     |+------------------+-------+

 

2.手动杀会话测试:

mysql> show processlist;

+----+------+-----------+------+---------+------+----------+------------------+| Id | User | Host      | db   | Command | Time | State    | Info            
 |+----+------+-----------+------+---------+------+----------+------------------+|  9 | root | localhost | NULL | Query   |    0 

| starting | 
show processlist 

|| 10 | root | localhost | NULL | Sleep   |    7 |          | NULL             

|+----+------+-----------+------+---------+------+----------+------------------+

2 rows in set (0.00 sec)mysql> kill 10;Query OK, 0 rows affected (0.00 sec)

 

3.查看状态变化及错误日志:

mysql> show global status like 'abort%';

+------------------+-------+| Variable_name    | Value |+------------------+-------+| 
Aborted_clients  | 1     || Aborted_connects | 2     |+------------------+-------+

结果：Aborted_clients有增加 error log无记录 ,类似的，睡眠时间超时后Aborted_clients有增加 error log中有Aborted connection相关记录。

 

会话异常退出一般会造成Aborted connection告警，即我们可以通过Aborted_clients状态变量的变化来反映出是否存在异常会话，

那么出现“Got an error reading communication packets” 类似告警的原因就很明了了，查询相关资料，总结出造成Aborted connection告警的可能原因如下：

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

3.问题避免与总结

其实Aborted connection告警是很难避免的，error log里或多或少会有少量Aborted connection信息，这种情况是可以忽略的，但是当你的error log里频繁出现Aborted connection告警，这时候就应该注意了，可能会对业务产生较大的影响。下面列举出几点避免错误的建议，希望对你有所帮助。

• 建议业务操作结束后，应用程序逻辑会正确关闭连接，以短连接替代长连接。
• 检查以确保max_allowed_packet的值足够高，并且客户端没有收到“数据包太大”消息。
• 确保客户端应用程序不中止连接，例如，如果PHP设置了max_execution_time为5秒，增加connect_timeout并不会起到作用，因为PHP会kill脚本。其他程序语言和环境也有类似的安全选项。
• 确保事务提交（begin和commit）都正确提交以保证一旦应用程序完成以后留下的连接是处于干净的状态。
• 检查是否启用了skip-name-resolve，检查主机根据其IP地址而不是其主机名进行身份验证。
• 尝试增加MySQL的net_read_timeout和net_write_timeout值，看看是否减少了错误的数量。

参考：

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