MySQL令人頭疼的Aborted告警案例分析
實戰
Part1:寫在最前
在MySQL的error log中,我們會經常性看到一些各類的Aborted connection錯誤,本文中會針對這類錯誤進行一個初步分析,并了解一個問題產生后的基本排查思路和方法。掌握這種方法是至關重要的,而不是出現問題了,去猜,去試。數據庫出現問題的時候需要DBA在短時間內快速解決問題,因此一個好與壞的DBA,區別也在于此。
Part2:種類
- [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:警告這兩個參數建議一起調節,能夠避免一些坑。
本文的兩個參數值采用的是默認值
- 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 會提升
- 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的哪個參數記載了這一問題
- [root@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1
- ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES)
- [root@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1
- ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES)
- [root@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1
- ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES)
- [root@HE3~]# mysql -uroot -pwrongpass -h127.0.0.1
- ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES)
- [root@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 記錄了密碼錯誤的這一問題
- mysql>show global status like 'aborted%';
- +------------------+-------+
- |Variable_name | Value |
- +------------------+-------+
- |Aborted_clients | 19 |
- |Aborted_connects | 5 |
- +------------------+-------+
- 2 rows inset (0.00 sec)
error log中,也記載了這類密碼輸錯的信息
- [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秒
- 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參數控制的,已經連接上數據的連接被殺掉。
- 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中記載的是
- [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
在這個案例中我們看下***連接數對數據庫連接的行為影響
- 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)
這里看到爆出了連接數過多的問題
- [root@HE3~]# mysql -uroot -pMANAGER -h127.0.0.1
- ERROR 1040 (HY000): Too many connections
而錯誤日志沒有任何記錄
Part7:案例4
第三方工具navicat select結果沒有出來的時候選擇停止則出現
clients上漲
- mysql>show global status like 'aborted%';
- +------------------+-------+
- |Variable_name | Value |
- +------------------+-------+
- |Aborted_clients | 28 |
- |Aborted_connects | 10 |
- +------------------+-------+
- 2 rows in set (0.00 sec)
error log日志記錄
- 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值,看看是否減少了錯誤的數量。
——總結——
通過這4個案例,我們能夠了解到,Aborted_clients、和Aborted_connects的區別,以及什么情況下會爆出什么樣的錯誤日志,文章第二節中的幾個Aborted錯誤是常見的錯誤,這類錯誤出現的時候腦海里要有一個理論知識,知道什么情況下,會出現什么樣的錯誤,以便快速定位問題。由于筆者的水平有限,編寫時間也很倉促,文中難免會出現一些錯誤或者不準確的地方,不妥之處懇請讀者批評指正。