DB(mysql)をアップデートしたところ、mysql-error-running.logに「Aborted connection (Got timeout reading communication packets)」が出力するようになった。

Zabbixバージョン: 3.0.7
OSバージョン: Amazon Linux AMI release 2016.03
mysqlバージョン: 5.6.23 ->  5.7.17 (今回アップデート)

事象:
mysql-error-running.logに以下のエラーが出力

2017-06-20T04:44:18.402168Z 78 [Note] Aborted connection 78 to db: 'zabbix' user: 'User' host: '10.x.x.xx' (Got timeout reading communication packets)

対応状況:

アップデート前もAbortedしていたようですので、
アップデートで勝手に変更されたログレベルを下げようと思っていますが(log_warnings=2を、1に戻す)、
そもそもこのエラーを出力していることが問題ないものか分かりません。
どなたかご教示いただけると幸いです。

アップデート後
mysql> show global status
-> ;
+-----------------------------------------------+--------------------------------------------------+
| Variable_name | Value |
+-----------------------------------------------+--------------------------------------------------+
| Aborted_clients | 16 |
| Aborted_connects | 2 |
| Binlog_cache_disk_use | 0

アップデート前
mysql> show global status;
+-----------------------------------------------+--------------+
| Variable_name | Value |
+-----------------------------------------------+--------------+
| Aborted_clients | 312 |
| Aborted_connects | 9 |
| Binlog_cache_disk_use | 0 |

コメント表示オプション

お好みのコメント表示方法を選び「設定の保存」をクリックすると変更が反映されます。
ユーザー fripper の写真

明確な原因まで特定できるほどではないのですが、ご参考になれば‥

zabbix_server のプロセスからの接続が原因となっているのか、それとも
Web Frontend 側からの接続が原因となっているのかを調べてみるのが良いかもしれません

zabbix_server 側の log から MySQL server has gone away のような出力を探してみる
Apache/Nginx等、Webフロントエンドcgiのログ出力を追ってみる‥等

MySQLをバージョンアップしたことにより、一部クエリの所要時間が変わってしまい
タイムアウトによって強制切断されている‥等の場合、Abort扱いになったかと思います

my.cnf 側で、以下のタイムアウト関連のパラメータを弄ってみると、何か効果があるかもしれません
connect_timeout
wait_timeout
interactive_timeout
net_read_timeout
net_write_timeout

ユーザー zab-SR の写真

fripper さん。
コメントありがとうございます。

コメントいただいた点については以下の通りです。

>Web Frontend 側からの接続が原因となっているのか
Zabbixコンソールで、監視データ表示処理中にブラウザ強制終了とかを試してみましたが再現せず、でした。

>zabbix_server 側の log から MySQL server has gone away のような出力を探してみる

zabbix_server.log には該当時刻(前後10分)に何らログがなく、Zabbixさんとしては何ら以上は認識していないようです。

>my.cnf 側で、以下のタイムアウト関連のパラメータを弄ってみると、何か効果があるかもしれません

タイムアウト関連パラメータの値は以下の通りです。
アップデートで変わっていたのは以下2点でしたが本件には関係ないかなぁと思っています。
have_statement_timeout  YES
slave_net_timeout 60
「弄ってみる」のは、すいません、できれば変更はしたくないので、他調査をもう少しやってみてから考えてみます。

■アップデート前のパラメータ
Variable_name Value
connect_timeout 10
delayed_insert_timeout 300

innodb_flush_log_at_timeout 1
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
rpl_stop_slave_timeout 31536000
slave_net_timeout 3600
wait_timeout 28800

■アップデート後のパラメータ
Variable_name Value
connect_timeout 10
delayed_insert_timeout 300
have_statement_timeout YES
innodb_flush_log_at_timeout 1
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
rpl_stop_slave_timeout 31536000
slave_net_timeout 60
wait_timeout 28800

広瀬です

Aborted_clients/connectsのエラー増加については、あまり意識されなくても良いと思います。
そもそも、log_warningsの値は0や1,2だけでは無く、0~18446744073709551615まで指定が
できます(公式参照ください)<64bitの場合

ログにwarning出すだけでそのレベルがそんなにあってどうするんだと呟きたくなりますが、仕様
なので、それは仕方ないと飲み込まざるをえませんが、2に設定しても中々ログファイルには当該
のエラーが出てこない場合もありました(この辺は5.5/5.6/5.7でも変わらないみたい)。

log_warningsを2にしてもエラーログには吐かれないが、値は増加していきました。100くらいにし
てようやく出力されましたが、増加件数とログ件数はマッチしません(1日くらい放置して増加は1000
以上あるのに、ログは数十件程度)<この辺の理屈は解りません

エラー起因は特定は簡単では無いと思います。

https://dev.mysql.com/doc/refman/5.6/ja/communication-errors.html

上記にピンポイントな公式資料ありますが、ここで挙げているのは、connection_timeout、及び、
fripperさんも出されている、wait_timeout、interactive_timeoutなどの設定値がそれぞれ起因し
てくる際に多いみたいですね。
それ以外だとクライアント側(この場合は、Zabbixサーバプロセス、及びPHP処理)の処理問題や
ネットワーク的な問題なども絡むみたいです。

Aborted connection 78 to db: 'zabbix' user: 'User' host: '10.x.x.xx'

上記のエラーに含まれる「78」の数値はMySQL内のスレッドIDですので、それを追っかけて見る
などの必要があり、リアルタイムでやるにしてもかなり厳しいことになると思います。
強いていえば、増加率が多い時間帯にどんな処理を行っているかは調べることはできるでしょう。
Aborted_connects、Aborted_clientsの値を差分監視して、増加率の多い時間にどんな処理が
行われているかを突き詰めていき、その時間の処理にHouseKeeperと重なっているとかで判断は
概ね付いてくるでしょう。

ただし、0には絶対出来ないと思います。そこは断言しておきます。

ユーザー zab-SR の写真

wakaba  さん

詳細のご説明ありがとうございます。
様々な原因で発生するんですね。

おっしゃる通り、原因特定は難しそうです。
具体的なサービス影響は出ていないので、今回は諦めておきます。

なお、以下は予定通り実施しておきます。
>log_warnings=2を、1に戻す

あらためて、ありがとうございました。