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_ERRORSCOUNT_HANDSHAKE_ERRORS として計上されている。 SUM_CONNECT_ERRORSmax_connect_errors に達するとブロックするらしい。 軽くソースを眺めてみたところ、 SUM_CONNECT_ERRORSCOUNT_HANDSHAKE_ERRORS は同じ値になるように見える…けど違うかもしれない。

ブロックされた後に接続を試みた数は COUNT_HOST_BLOCKED_ERRORS として計上されている。

ところで、127.0.0.1::1 のようなループバックアドレスはブロック対象にはならない。 外部からの MySQL プロトコルに従わない怪しげな接続をブロックための仕組みのようで、ちゃんと MySQL プロトコルに従ってるような攻撃には無力。

[追記]

はてブのコメントより

MySQL の接続まわりのエラー - @tmtms のメモ

"Host '〜' is blocked because of many connection errors" こんなのあったんだ・・skip_name_resolve だと host_cache 自体が有効にならないから発生しない模様

2020/09/09 15:14
b.hatena.ne.jp

そうなんですよね。クライアントの名前解決をキャッシュする機構に乗っかってるんで、skip_name_resolve が有効だとそもそも発生しない。

実際には skip_name_resolve を設定している環境は多いと思う。名前解決しないぶん速いし。

なのでやっぱりこの仕組みがどれくらいセキュリティ的に意味があるのかは疑問だったりする。

ユーザー名ごとの連続認証失敗回数

今回これを調べてて知ったんだけど、ちゃんと 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というユーザー名で接続すると待たされない。

いつからだろう。前からこんな仕組みあったっけ…?

[追記]

Twitter で指摘していただいた。

connection_control プラグインがインストールされていたからだった。 MySQL Parameters のために全プラグインをインストールした環境で試してた…。

デフォルト状態ではこのプラグインはインストールされてないので、何回失敗しても遅延することはない。

Aborted_clients と Aborted_connects

ステータス変数に Aborted_clientsAboreted_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 からの接続でも働く。