MySQLのAborted_connects増加現象
お世話になります、
近々Zabbix監視基盤のカットオーバーを控えているため、
ログ確認とDBチューニングを行っていたところ、MySQLのAborted_connects が
増えていく事象を発見しました。
zabbix server側のログを見ても犯人がわかりません。
MySQL のサービス再起動直後にshow statusで状況を見てみましたが
再起動直後ですでに141カウントされていました。
zabbixは普通に使えて監視もデータも問題なく蓄積されている様なのですが、
この事象は放置でもいいのか、気にしたほうがいいのか検討がつかず
質問させていただきました。
よろしくお願いいたします。
CentOS 6.5 (x64)
MySQL 5.6.17 / InnoDBを使用
Zabbix 2.2.3 (revision 44105)
mysql> show status;
+-----------------------------------------------+-------------+
| Variable_name | Value |
+-----------------------------------------------+-------------+
| Aborted_clients | 0 |
| Aborted_connects | 141 |
20938:20140531:210726.934 syncing history data...
20938:20140531:210726.937 syncing history data done
20938:20140531:210726.937 syncing trends data...
20938:20140531:210726.972 syncing trends data done
20938:20140531:210726.972 Zabbix Server stopped. Zabbix 2.2.3 (revision 44105).
25103:20140531:210748.664 Starting Zabbix Server. Zabbix 2.2.3 (revision 44105).
25103:20140531:210748.664 ****** Enabled features ******
25103:20140531:210748.664 SNMP monitoring: YES
25103:20140531:210748.664 IPMI monitoring: YES
25103:20140531:210748.664 WEB monitoring: YES
25103:20140531:210748.664 VMware monitoring: YES
25103:20140531:210748.664 Jabber notifications: YES
25103:20140531:210748.664 Ez Texting notifications: YES
25103:20140531:210748.664 ODBC: YES
25103:20140531:210748.664 SSH2 support: YES
25103:20140531:210748.664 IPv6 support: YES
25103:20140531:210748.664 ******************************
25103:20140531:210748.664 using configuration file: /etc/zabbix/zabbix_server.conf
25103:20140531:210748.667 current database version (mandatory/optional): 02020000/02020001
25103:20140531:210748.667 required mandatory version: 02020000
25109:20140531:210748.681 server #1 started [configuration syncer #1]
25122:20140531:210748.696 server #14 started [trapper #1]
25124:20140531:210748.697 server #16 started [trapper #3]
25126:20140531:210748.697 server #18 started [trapper #5]
25129:20140531:210748.697 server #21 started [icmp pinger #3]
25131:20140531:210748.697 server #23 started [icmp pinger #5]
25123:20140531:210748.698 server #15 started [trapper #2]
25125:20140531:210748.699 server #17 started [trapper #4]
25127:20140531:210748.699 server #19 started [icmp pinger #1]
25128:20140531:210748.699 server #20 started [icmp pinger #2]
25130:20140531:210748.699 server #22 started [icmp pinger #4]
25132:20140531:210748.699 server #24 started [icmp pinger #6]
25134:20140531:210748.700 server #26 started [icmp pinger #8]
25136:20140531:210748.700 server #28 started [icmp pinger #10]
25138:20140531:210748.700 server #30 started [icmp pinger #12]
25140:20140531:210748.702 server #32 started [icmp pinger #14]
25142:20140531:210748.703 server #34 started [icmp pinger #16]
25133:20140531:210748.704 server #25 started [icmp pinger #7]
25144:20140531:210748.705 server #36 started [icmp pinger #18]
25135:20140531:210748.707 server #27 started [icmp pinger #9]
25137:20140531:210748.707 server #29 started [icmp pinger #11]
25139:20140531:210748.708 server #31 started [icmp pinger #13]
25141:20140531:210748.708 server #33 started [icmp pinger #15]
25143:20140531:210748.708 server #35 started [icmp pinger #17]
25146:20140531:210748.708 server #38 started [icmp pinger #20]
25150:20140531:210748.708 server #42 started [timer #2]
25148:20140531:210748.709 server #40 started [housekeeper #1]
25148:20140531:210748.709 executing housekeeper
25103:20140531:210748.709 server #0 started [main process]
25145:20140531:210748.709 server #37 started [icmp pinger #19]
25152:20140531:210748.709 server #44 started [timer #4]
25147:20140531:210748.709 server #39 started [alerter #1]
25154:20140531:210748.709 server #46 started [timer #6]
25151:20140531:210748.709 server #43 started [timer #3]
25149:20140531:210748.709 server #41 started [timer #1]
25153:20140531:210748.710 server #45 started [timer #5]
25155:20140531:210748.710 server #47 started [timer #7]
25110:20140531:210748.715 server #2 started [db watchdog #1]
25169:20140531:210748.719 server #57 started [history syncer #2]
25160:20140531:210748.721 server #48 started [timer #8]
25161:20140531:210748.722 server #49 started [timer #9]
25162:20140531:210748.722 server #50 started [timer #10]
25163:20140531:210748.722 server #51 started [http poller #1]
25164:20140531:210748.722 server #52 started [http poller #2]
25165:20140531:210748.722 server #53 started [http poller #3]
25170:20140531:210748.724 server #58 started [history syncer #3]
25171:20140531:210748.724 server #59 started [history syncer #4]
25168:20140531:210748.728 server #56 started [history syncer #1]
25172:20140531:210748.730 server #60 started [escalator #1]
25173:20140531:210748.730 server #61 started [ipmi poller #1]
25175:20140531:210748.731 server #63 started [proxy poller #1]
25177:20140531:210748.731 server #64 started [self-monitoring #1]
25174:20140531:210748.734 server #62 started [snmp trapper #1]
25111:20140531:210748.833 server #3 started [poller #1]
25112:20140531:210748.834 server #4 started [poller #2]
25118:20140531:210748.839 server #10 started [poller #8]
25116:20140531:210748.841 server #8 started [poller #6]
25120:20140531:210748.845 server #12 started [poller #10]
25121:20140531:210748.846 server #13 started [unreachable poller #1]
25114:20140531:210748.847 server #6 started [poller #4]
25117:20140531:210748.847 server #9 started [poller #7]
25119:20140531:210748.849 server #11 started [poller #9]
25115:20140531:210748.850 server #7 started [poller #5]
25113:20140531:210748.851 server #5 started [poller #3]
25166:20140531:210748.854 server #54 started [discoverer #1]
25167:20140531:210748.857 server #55 started [discoverer #2]
25148:20140531:210748.962 housekeeper [deleted 919 hist/trends, 0 items, 0 events, 0 sessions, 0 alarms, 0 audit items in 0.234559 sec, idle 2 hour(s)]
↓userparameterを使用するMySQLの監視接続設定の途中でまだ完成していません。その関係？
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
140531 21:07:39 mysqld_safe mysqld from pid file /data/xxxx.hogehoge.co.jp.pid ended
140531 21:07:40 mysqld_safe Starting mysqld daemon with databases from /data
2014-05-31 21:07:40 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2014-05-31 21:07:40 25049 [Note] Plugin 'FEDERATED' is disabled.
2014-05-31 21:07:40 7fd44416b720 InnoDB: Warning: Setting innodb_checksums to OFF is DEPRECATED. This option may be removed in future releases. You should set innodb_checksum_algorithm=NONE instead.
2014-05-31 21:07:40 25049 [Note] InnoDB: Using atomics to ref count buffer pool pages
2014-05-31 21:07:40 25049 [Note] InnoDB: The InnoDB memory heap is disabled
2014-05-31 21:07:40 25049 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2014-05-31 21:07:40 25049 [Note] InnoDB: Compressed tables use zlib 1.2.3
2014-05-31 21:07:40 25049 [Note] InnoDB: Using Linux native AIO
2014-05-31 21:07:40 25049 [Note] InnoDB: Using CPU crc32 instructions
2014-05-31 21:07:40 25049 [Note] InnoDB: Initializing buffer pool, size = 8.0G
2014-05-31 21:07:40 25049 [Note] InnoDB: Completed initialization of buffer pool
2014-05-31 21:07:40 25049 [Note] InnoDB: Highest supported file format is Barracuda.
2014-05-31 21:07:41 25049 [Note] InnoDB: 128 rollback segment(s) are active.
2014-05-31 21:07:41 25049 [Note] InnoDB: Waiting for purge to start
2014-05-31 21:07:41 25049 [Note] InnoDB: 5.6.17 started; log sequence number 865937049
2014-05-31 21:07:41 25049 [Note] Server hostname (bind-address): '*'; port: 3306
2014-05-31 21:07:41 25049 [Note] IPv6 is not available.
2014-05-31 21:07:41 25049 [Note] - '0.0.0.0' resolves to '0.0.0.0';
2014-05-31 21:07:41 25049 [Note] Server socket created on IP: '0.0.0.0'.
2014-05-31 21:07:41 25049 [Note] Event Scheduler: Loaded 0 events
2014-05-31 21:07:41 25049 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.17' socket: '/var/lib/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL)
[mysqld]
user=mysql
datadir=/data
ignore-db-dir = lost+found
socket=/var/lib/mysql/mysql.sock
character-set-server=utf8
log_warnings = 1
max_connections = 800
thread_cache_size = 512
table_open_cache = 2048
table_definition_cache = 1500
open_files_limit = 4095
wait_timeout = 180
interactive_timeout = 180
join_buffer_size = 2048M
sort_buffer_size = 128M
read_rnd_buffer_size = 128M
# InnoDB
innodb_file_per_table=1
innodb_autoextend_increment = 1
innodb_file_format=Barracuda
innodb_buffer_pool_size = 8192M
innodb_thread_concurrency = 20
innodb_flush_log_at_trx_commit = 1
innodb_log_files_in_group = 5
innodb_buffer_pool_instances = 2
innodb_log_buffer_size = 128M
innodb_log_file_size = 1024M
innodb_support_xa=0
innodb_checksums=0
innodb_doublewrite=0
innodb_fast_shutdown=0
innodb_log_group_home_dir = /data
[mysqld_safe]
log-error=/db_log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid
[mysql]
default-character-set=utf8
KAZ - 投稿数: 1085
tomopa2さん
近々Zabbix監視基盤のカットオーバーを控えているため、
ログ確認とDBチューニングを行っていたところ、MySQLのAborted_connects が
増えていく事象を発見しました。
wait_timeout とinteractive_timeoutが180秒になってます。
下のURL辿ると載ってますが、wait_timeout とinteractive_timeout超えて切断するとAborted_clientsを増やすようです。
上記設定だと３分以上の待ち時間が発生するプロセスは切断されてAborted_clientsが加算されます。
※：デフォルトは８時間ですよね？短くし過ぎでは…A(^^;
尚、Zabbixはセッション切れていたら接続し直すので処理的には問題無いと思います。
http://dev.mysql.com/doc/refman/5.1/ja/server-status-variables.html
http://dev.mysql.com/doc/refman/5.1/ja/communication-errors.html
↓userparameterを使用するMySQLの監視接続設定の途中でまだ完成していません。その関係？
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
MySQLにroot@localhostでアクセスできるようにしてやればよいのでは？
TNK - 投稿数: 4769
すでにKAZさんからコメントを頂いていますが、少しだけ補足させ
て頂きます。
Aborted_connectsが増加するということは、タイムアウト関連も含
めて、
・正常にDBへの接続切断を行っていないアプリケーションがある
・接続後のレスポンスがタイムアウトした
・やり取りしている最中にクライアントが終了した
・クライアントがDBにアクセスする権限が無い
・パスワード誤り
・通信内に正しい情報が設定されていない
・接続時のタイムアウト
などの要因が考えられるようです。
提示頂いたログ内で、UserParameterを利用してMySQLにアクセスし
ようとして認証エラーとなっている、つまり、UserParameterが正
しく動くように設定できていないのも要因の1つだと思われます。
MySQLへの接続でパスワードを必須にされているのであれば、MySQL
の管理テーブルにアクセスできるユーザとパスワードを利用してア
クセスするようにきちんと設定を行ってください。
無視してよい値だとは思いませんので、なぜそのような警告がカウ
ントされるのか、MySQLの利用方法や監視設定なども再度ご確認く
ださい。
ご参考： MySQL関連
http://dev.mysql.com/doc/refman/5.6/en/server-status-variables.html
http://dev.mysql.com/doc/refman/5.6/en/communication-errors.html
http://dev.mysql.com/doc/refman/5.1/ja/server-status-variables.html
http://dev.mysql.com/doc/refman/5.1/ja/communication-errors.html
ご参考： Zabbixのテンプレート「Template App MySQL」の使い方
http://www.slideshare.net/qryuu/zabbix-20zabbix20mysql
KAZ - 投稿数: 1085
TNKさん
フォローありがとうございます。
提示頂いたログ内で、UserParameterを利用してMySQLにアクセスし
ようとして認証エラーとなっている、つまり、UserParameterが正
しく動くように設定できていないのも要因の1つだと思われます。
そうですね、これの影響見落としてました。A(^^;
tomopa2 - 投稿数: 23
KAZさん、TNKさん
お二方フォローありがとうございます。
ご指摘いただいた、timeout値の見直しを実施し、症状が改善されました。
＞wait_timeout とinteractive_timeoutが180秒になってます。
UserParameterも正しく設定してあげることで、
Aborted_connectsが増えることはなくなりました。
勉強になりました、ありがとうございました。
今後ともよろしくお願いいたします。