MySQL の接続まわりのエラー
MySQL で Host '〜' is blocked because of many connection errors が出るのってどういうときだっけ…とふと思ったので接続周りを調べてみた。
クライアントごとの連続接続失敗によるブロック
マニュアル https://dev.mysql.com/doc/refman/8.0/en/blocked-host.html にはこう書かれてる (DeepL翻訳)
システム変数 max_connect_errors の値は、何回連続して中断される接続要求を許可するかを決定します。max_connect_errors が接続に成功せずにリクエストに失敗した後、mysqld は何か問題がある (誰かが侵入しようとしているなど) と判断し、FLUSH HOSTS 文、Performance Schema host_cache テーブルを切り捨てる TRUNCATE TABLE 文、または mysqladmin flush-hosts コマンドを実行してホストキャッシュをフラッシュするまで、それ以上の接続からホストをブロックします。
一見すると認証に失敗した場合もこれに含まれるんじゃないかと読めるんだけど、実は認証失敗はこれには含まれないっぽい。
なので同じクライアントから何回失敗してもブロックされることはない。
max_connect_errors のデフォルト値は 100 (MySQL 5.6 より前は 10) なので、そんなに試すのは嫌なので 3 に設定しておく。
mysql> set global max_connect_errors=3
テキトーなクライアントから不正なパスワードで接続を試みてみる。
~% mysql -u test -h 192.168.68.1 -pinvalid
ERROR 1045 (28000): Access denied for user 'test'@'hogehoge' (using password: YES)
~% mysql -u test -h 192.168.68.1 -pinvalid
ERROR 1045 (28000): Access denied for user 'test'@'hogehoge' (using password: YES)
~% mysql -u test -h 192.168.68.1 -pinvalid
ERROR 1045 (28000): Access denied for user 'test'@'hogehoge' (using password: YES)
~% mysql -u test -h 192.168.68.1 -pinvalid
ERROR 1045 (28000): Access denied for user 'test'@'hogehoge' (using password: YES)
~% mysql -u test -h 192.168.68.1 -pinvalid
ERROR 1045 (28000): Access denied for user 'test'@'hogehoge' (using password: YES)
5回やってもブロックされない。
performance_schema.host_cache を見ると COUNT_AUTHENTICATION_ERRORS には計上されている。
mysql> select * from host_cache\G
*************************** 1. row ***************************
IP: 192.168.68.103
HOST: hogehoge
HOST_VALIDATED: YES
SUM_CONNECT_ERRORS: 0
COUNT_HOST_BLOCKED_ERRORS: 0
COUNT_NAMEINFO_TRANSIENT_ERRORS: 0
COUNT_NAMEINFO_PERMANENT_ERRORS: 0
COUNT_FORMAT_ERRORS: 0
COUNT_ADDRINFO_TRANSIENT_ERRORS: 0
COUNT_ADDRINFO_PERMANENT_ERRORS: 0
COUNT_FCRDNS_ERRORS: 0
COUNT_HOST_ACL_ERRORS: 0
COUNT_NO_AUTH_PLUGIN_ERRORS: 0
COUNT_AUTH_PLUGIN_ERRORS: 0
COUNT_HANDSHAKE_ERRORS: 0
COUNT_PROXY_USER_ERRORS: 0
COUNT_PROXY_USER_ACL_ERRORS: 0
COUNT_AUTHENTICATION_ERRORS: 5
COUNT_SSL_ERRORS: 0
COUNT_MAX_USER_CONNECTIONS_ERRORS: 0
COUNT_MAX_USER_CONNECTIONS_PER_HOUR_ERRORS: 0
COUNT_DEFAULT_DATABASE_ERRORS: 0
COUNT_INIT_CONNECT_ERRORS: 0
COUNT_LOCAL_ERRORS: 0
COUNT_UNKNOWN_ERRORS: 0
FIRST_SEEN: 2020-09-07 00:14:15
LAST_SEEN: 2020-09-07 00:14:19
FIRST_ERROR_SEEN: 2020-09-07 00:14:15
LAST_ERROR_SEEN: 2020-09-07 00:14:19
1 row in set (0.00 sec)
じゃあブロックされるのはどういう時なの？ っていうと、接続の初期プロトコルが完了しなかった場合らしい。
試しに 3306ポートに接続してすぐに切断するようなのを3回繰り返した後に、接続を試みるとブロックされる。
~% ruby -rsocket -e 'TCPSocket.new("192.168.68.103", 3306)'
~% ruby -rsocket -e 'TCPSocket.new("192.168.68.103", 3306)'
~% ruby -rsocket -e 'TCPSocket.new("192.168.68.103", 3306)'
~% mysql -u test -h 192.168.68.1 -pinvalid
ERROR 1129 (HY000): Host '192.168.68.103' is blocked because of many connection errors; unblock with 'mysqladmin flush-hosts'
~%
host_cache はこんな感じ:
mysql> select * from host_cache\G
*************************** 1. row ***************************
IP: 192.168.68.103
HOST: hogehoge
HOST_VALIDATED: YES
SUM_CONNECT_ERRORS: 3
COUNT_HOST_BLOCKED_ERRORS: 1
COUNT_NAMEINFO_TRANSIENT_ERRORS: 0
COUNT_NAMEINFO_PERMANENT_ERRORS: 0
COUNT_FORMAT_ERRORS: 0
COUNT_ADDRINFO_TRANSIENT_ERRORS: 0
COUNT_ADDRINFO_PERMANENT_ERRORS: 0
COUNT_FCRDNS_ERRORS: 0
COUNT_HOST_ACL_ERRORS: 0
COUNT_NO_AUTH_PLUGIN_ERRORS: 0
COUNT_AUTH_PLUGIN_ERRORS: 0
COUNT_HANDSHAKE_ERRORS: 3
COUNT_PROXY_USER_ERRORS: 0
COUNT_PROXY_USER_ACL_ERRORS: 0
COUNT_AUTHENTICATION_ERRORS: 0
COUNT_SSL_ERRORS: 0
COUNT_MAX_USER_CONNECTIONS_ERRORS: 0
COUNT_MAX_USER_CONNECTIONS_PER_HOUR_ERRORS: 0
COUNT_DEFAULT_DATABASE_ERRORS: 0
COUNT_INIT_CONNECT_ERRORS: 0
COUNT_LOCAL_ERRORS: 0
COUNT_UNKNOWN_ERRORS: 0
FIRST_SEEN: 2020-09-07 00:21:52
LAST_SEEN: 2020-09-07 00:22:04
FIRST_ERROR_SEEN: 2020-09-07 00:21:52
LAST_ERROR_SEEN: 2020-09-07 00:22:04
1 row in set (0.00 sec)
接続してすぐに切断した数は SUM_CONNECT_ERRORS と COUNT_HANDSHAKE_ERRORS として計上されている。
SUM_CONNECT_ERRORS が max_connect_errors に達するとブロックするらしい。
軽くソースを眺めてみたところ、 SUM_CONNECT_ERRORS と COUNT_HANDSHAKE_ERRORS は同じ値になるように見える…けど違うかもしれない。
ブロックされた後に接続を試みた数は COUNT_HOST_BLOCKED_ERRORS として計上されている。
ところで、127.0.0.1 や ::1 のようなループバックアドレスはブロック対象にはならない。
外部からの MySQL プロトコルに従わない怪しげな接続をブロックための仕組みのようで、ちゃんと MySQL プロトコルに従ってるような攻撃には無力。
なおこれはクライアントの名前解決をキャッシュする機構に乗っかってるんで、skip_name_resolve が有効だとそもそも発生しない。
実際には skip_name_resolve を設定している環境は多いと思う。名前解決しないぶん速いし。
なのでやっぱりこの仕組みがどれくらいセキュリティ的に意味があるのかは疑問だったりする。
ユーザー名ごとの連続認証失敗回数
今回これを調べてて知ったんだけど、connection_control プラグインがインストールされていると、
「ちゃんと MySQL プロトコルに従ってるけど認証失敗するような接続」を連続で試みると、エラーが返るまでの時間が延びていくらしい。
~% time mysql -u test -h 127.0.0.1
ERROR 1045 (28000): Access denied for user 'test'@'localhost' (using password: NO)
real 0m0.060s
user 0m0.027s
sys 0m0.009s
~% time mysql -u test -h 127.0.0.1
ERROR 1045 (28000): Access denied for user 'test'@'localhost' (using password: NO)
real 0m0.027s
user 0m0.012s
sys 0m0.009s
~% time mysql -u test -h 127.0.0.1
ERROR 1045 (28000): Access denied for user 'test'@'localhost' (using password: NO)
real 0m0.042s
user 0m0.011s
sys 0m0.012s
~% time mysql -u test -h 127.0.0.1
ERROR 1045 (28000): Access denied for user 'test'@'localhost' (using password: NO)
real 0m1.017s
user 0m0.000s
sys 0m0.013s
~% time mysql -u test -h 127.0.0.1
ERROR 1045 (28000): Access denied for user 'test'@'localhost' (using password: NO)
real 0m2.036s
user 0m0.016s
sys 0m0.004s
~% time mysql -u test -h 127.0.0.1
ERROR 1045 (28000): Access denied for user 'test'@'localhost' (using password: NO)
real 0m3.016s
user 0m0.004s
sys 0m0.008s
~% time mysql -u test -h 127.0.0.1
ERROR 1045 (28000): Access denied for user 'test'@'localhost' (using password: NO)
real 0m4.049s
user 0m0.017s
sys 0m0.014s
~% time mysql -u test -h 127.0.0.1 -p******** -e ''
mysql: [Warning] Using a password on the command line interface can be insecure.
real 0m5.027s
user 0m0.009s
sys 0m0.009s
~%
3回目まではすぐにエラーが返るんだけど、4回目以降は1秒ずつ延びていく。正しいパスワードでも時間が掛かるので認証処理の前にスリープしてるっぽい。
これはホストブロックと違って、127.0.0.1 でも有効だし、どうやらクライアントじゃなくてユーザー名ごとに認証失敗回数を保持しているらしい。
同じクライアントであっても異なるユーザー名であればすぐにエラーが返るし、異なるクライアントからの接続でも同じユーザー名であれば失敗回数を保持している。MySQLに存在していないユーザー名でも効く。
クライアントAからtestというユーザー名で認証を5回失敗した後に、クライアントBから同じtestというユーザー名で接続しようとすると3秒待たされ、クライアントAからtest2というユーザー名で接続すると待たされない。
デフォルト状態では connection_control プラグインはインストールされてないので、何回失敗しても遅延することはない。
Aborted_clients と Aborted_connects
ステータス変数に Aborted_clients と Aboreted_connects というのがある。どう違うんだっけ…と毎回調べてすぐに忘れるのでメモ。
mysql> show status like 'aborted%';
+------------------+-------+
| Variable_name | Value |
+------------------+-------+
| Aborted_clients | 0 |
| Aborted_connects | 0 |
+------------------+-------+
2 rows in set (0.00 sec)
まあ答えはマニュアル https://dev.mysql.com/doc/refman/8.0/en/communication-errors.html に書かれてるんだけど。
Aborted_clients は接続成功後に終了プロトコルなしでTCP接続が切断した場合にカウントされる。
たとえばクライアントプログラムが落ちたり、KILL で接続を強制切断したり、wait_timeout の時間クエリが何も発行されずに接続が切断された場合など。
Aborted_connects は接続が失敗した場合にカウントされる。
接続してすぐに切断したようなプロトコルが不正な場合や、認証に失敗した場合も含まれる。これは 127.0.0.1 からの接続でも働く。
Discussion