akishin999の日記

調べた事などを書いて行きます。

HAProxy 環境で MySQL 接続時にエラー

久しぶりに自宅サーバにアクセスしてみたら、DB 接続系のアプリが軒並み 500 エラーになってしまっていました。
慌てて調べますが、Rails アプリのログにも、HAProxy のログにも特に異常は見られません。

ためしにコマンドラインから DB への接続を試みると、HAProxy 経由でも直接 DB サーバを指定しても、以下のエラーメッセージが表示されて接続できなくなっていました。

Host 'hostname' is blocked because of many connection errors; unblock with 'mysqladmin flush-hosts'


他のマシンからは接続できるので、どうやらメッセージ通りこの Web サーバのみが弾かれてしまっているようです。

エラーメッセージで検索すると以下のようなページが見つかりました。


MySQL :: MySQL 4.1 リファレンスマニュアル :: A.2.5 Host '...' is blocked エラー
http://dev.mysql.com/doc/refman/4.1/ja/blocked-host.html


上記を参考に、エラーメッセージにもある通り以下を実行。

# mysqladmin -h127.0.0.1 -uroot -p flush-hosts


実行後にブラウザから問題のアプリを開くと、今度はちゃんと表示されるようです。
「直ったか?」と思い、しばらくアクセスしていると、やはり 500 エラーに。

「max_connect_errors」はデフォルト 10 回ということなので、少なすぎるのでしょうか?
試しに以下を実行してみましたが、間隔が長くなっただけで、やはりしばらくするとエラーになってしまいます。

mysql> set global max_connect_errors = 1000;
Query OK, 0 rows affected (0.00 sec)

mysql> show global variables like 'max_connect_errors';
+--------------------+-------+
| Variable_name      | Value |
+--------------------+-------+
| max_connect_errors | 1000  |
+--------------------+-------+
1 row in set (0.00 sec)


DB サーバ側から以下のように netstat でポート 3306 へのアクセスをしばらく監視してみましたが、とても短時間に 1000 回の設定を超えるほど頻繁なアクセスが来ているようには見えません。

watch -n -1 -d 'netstat -na | grep :3306'


こうなったら仕方がないので、DB サーバ側の iptables に以下のルールを追加しました。

iptables -A INPUT -s 192.168.0.3 -p tcp --dport 3306 -j LOG
iptables -A INPUT -p tcp --dport 3306 -j ACCEPT


出力されたログを見てみると、確かに問題のサーバから一定間隔でアクセスがあるようです。
ログの単調な間隔からしてどうもヘルスチェックがあやしい・・・。

という事で、HAProxy の設定ファイルから check パラメータを外してみると・・・見事ログが止まりました!
といってもせっかくの冗長構成、ヘルスチェックを止めるわけにはいきません。

今度は HAProxy 方面から検索してみると、以下の記事を発見。


option mysql-check
http://agiletesting.blogspot.com/2010/02/use-haproxy-14-if-you-need-mysql-health.html


どうやら 1.4 系へバージョンアップして、「option mysql-check」を指定する事で、MySQL にとって不正なパケットと認識されない方法でヘルスチェックが行われるようになるようです。

global
        maxconn         10000
        daemon
        nbproc          1
        user            haproxy
        group           haproxy
        log             /dev/log local0 debug

defaults
        log             global
        mode            tcp
        timeout client  60000
        timeout server  30000
        timeout connect 4000
        retries         3

listen  mysql
        bind            :3306
        mode            tcp
        option          mysql-check
        balance         roundrobin
        server          db01 192.168.0.4:3306 check rise 1 fall 1
        server          db02 192.168.0.5:3306 check rise 1 fall 1 backup
        option          persist


システムにインストールされていた HAProxy は 1.3.21 だったので、まずは 1.4.8 へと更新しました。

ちなみに HAProxy はソースから入れてあったのですが、 1.3.21 -> 1.4.8 へのアップデートでは特にアンインストールなどはせず、サービスを停止してから、普通に最新版を上書きインストールしたところ問題なく動作するようです。

というわけで、haproxy を 1.3.21 -> 1.4.8 へと更新し、haproxy.cfg に上記のように「option mysql-check」を追加したところ、無事現象は収束しました。


・・・と思いましたが、暫く放置してから見てみると、やはり同様のエラーが発生していました・・・。

バージョンアップのお陰か、今度はログに以下のように記録されています。

Sep 26 10:42:25 web01 haproxy[11021]: Server mysql/db01 is DOWN, reason: Layer7 wrong status, code: 0, info: "Host 'web01' is blocked because of many connection errors; unblock with 'mysqladmin flush-hosts'", check duration: 3ms.
Sep 26 10:42:26 web01 haproxy[11022]: Backup Server mysql/db02 is DOWN, reason: Layer7 wrong status, code: 0, info: "Host 'web01' is blocked because of many connection errors; unblock with 'mysqladmin flush-hosts'", check duration: 1ms.
Sep 26 10:42:26 web01 haproxy[11022]: proxy mysql has no server available!


上記の記事のコメント欄をよく読むと、やはりこれでは駄目だと突っ込んでいる人がいますね・・・。

で、対処方法として以下の記事が紹介されていました。


Sysbible » Blog Archive » Having HAProxy check mysql status through a xinetd script
http://sysbible.org/2008/12/04/having-haproxy-check-mysql-status-through-a-xinetd-script/


xinetd を使って MySQL の死活監視を行い、その結果を haproxy の「option httpchk」での監視に使用する、といった方式のようです。


また、解決と言えるかどうか微妙ですが、他の回避方法として、このエラー自体を通知しないようにする方法が MySQL のリファレンスに記載されていました。


MySQL :: MySQL 5.1 リファレンスマニュアル (オンラインヘルプ) :: 8.5.6.3 FLUSH 構文
http://dev.mysql.com/doc/refman/5.1-olh/ja/flush.html


「max_connect_errors=999999999」を設定すればいいみたいです。
とりあえず自宅なのとこちらの方が手軽なので、この設定を my.cnf に追加し MySQL を再起動しました。


今度こそ再発しなければいいのですが・・・。


それにしても、こんな重大な設定ミスに今まで気付かなかったとは・・・。
どうやら以前試しに設定を弄っていた際に check を入れてしまい、そのまま最近までサービスの再起動を忘れていたみたいです。

検証用の自宅サーバなので特に問題はなかったのですが、今後は気をつけようと思います。

2016/03/03 追記

当時は全く気付きませんでしたが、今日職場で同様の事象が発生したので検索していたら以下の記事を見つけました。

HAProxyを使ってMySQLの負荷分散をする時はmysql-checkのuserオプションを使う « サーバーワークス エンジニアブログ
http://blog.serverworks.co.jp/tech/2013/05/27/haproxy-mysql-check-user-option/

こちらを読んで頂けると判りますが、HAProxy で mysql-check を使う場合は user オプションで MySQL 接続ユーザを指定する必要があるとのことです。

ですので、同じエラーでこのページに辿り着いた方は安直に「max_connect_errors=999999999」を設定するのではなく、こちらの設定を試してみて下さい。