MySQL Aborted告警案例分析

SEian.G

发布于 2021-11-23 11:23:09

4250

发布于 2021-11-23 11:23:09

昨天频繁的收到MySQL实例关于Aborted告警邮件，看到告警邮件的实例信息，测试实例，优先级没没那么高，晚点抽空在看，可能到时候就好了，抱着侥幸的心理继续划水，但是没过1个小时，收到50多封告警邮件，实在受不了了，准备放下手头的事情优先处理该告警问题；如下是告警邮件相关信息截图：

从告警看，是由于MySQL实例状态变量Aborted_connects不断增加导致的，正常情况下，该变量值应该保持0，但是现在在不断的累加，那么在什么情况下该状态值会不断的增加呢？这是解决该问题最先需要弄清楚的；

那么先看一下具体的现象:

Aborted_connects的值不断的增加，系统层面存在大量的TIME_WAIT状态的TCP连接，而且都来自于同一个IP地址，如下所示：

# netstat -tuplan | grep 4306 | grep TIME_WAIT  | wc -l
1159
 
下面是部分tcp连接
......
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:7586      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:5198      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:8314      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:5076      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:7610      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:7962      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:6546      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:5354      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:6596      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:8342      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:7184      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:7476      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:5994      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:7322      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:5340      TIME_WAIT   -                   
tcp        0      0 192.168.7.xxx:4306      10.21.1.28:6798      TIME_WAIT   -

实例层面可以看到，Aborted_connects的值不断的增加

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

那么，先来看一下错误日志，看看错误日志中是否有相关记录，但是查看错误日志，并没有发现错误信息；感觉很疑惑；

接来下，我们先看一下在什么情况下Aborted_connects的值会不断的增加？

如下是官方文档针对该状态量的解释以及该变量不断增加可能产生的原因的说明：

Aborted_connects

The number of failed attempts to connect to the MySQL server.

If a client is unable even to connect, the server increments the Aborted_connects status variable. Unsuccessful connection attempts can occur for the following reasons:

A client attempts to access a database but has no privileges for it.
A client uses an incorrect password.
A connection packet does not contain the right information.
It takes more than connect_timeout seconds to obtain a connect packet.

从上面可以看到，如上的四种情况会导致该变量值不断增加：

客户端尝试连接数据库，但是没有权限
客户端使用了错误的密码
连接的数据包包含不正确的信息
超过连接时间限制，主要有这个参数控制connect_timeout，mysql默认是10s，基本除非网络环境极端不好，一般不会超时

但是从错误日志中并没有发现有用的信息，接下来，打开general_log来看一下数据库相关的操作信息，开启后，发现了新大陆，general_log日志中记录了大量如下的日志：

2021-11-18T09:16:19.234261Z      8328 Connect   dev_test_rwh@10.21.1.28 on game_report_sg using SSL/TLS
2021-11-18T09:16:19.255753Z      8329 Connect   dev_test_rwh@10.21.1.28 on game_report_sg using SSL/TLS
2021-11-18T09:16:19.352826Z      8330 Connect   dev_test_rwh@10.21.1.28 on game_report_sg using SSL/TLS
2021-11-18T09:16:19.452269Z      8331 Connect   dev_test_rwh@10.21.1.28 on game_report_sg using SSL/TLS

从该日志信息看，可以发现，从客户端10.21.1.28发起连接，通过dev_test_rwh账户连接数据库game_report_sg，但是可以发现，该账户却没有数据库game_report_sg的访问权限导致，那么正常情况，没有访问权限连接的客户端应该会会出现报错信息，于是连接业务人员查看相关连接情况，最终把该问题解决掉；

本文参与腾讯云自媒体同步曝光计划，分享自微信公众号。

原始发表：2021-11-22，如有侵权请联系 cloudcommunity@tencent.com 删除

云数据库 SQL Server