ここ最近、このブログが昼過ぎからアクセスできなくなるという現象が発生していました。たいてい夕方にサーバー再起動して復旧していたのですが多くの方にご迷惑をおかけしたと思います。
wordpressの宿命なのかもしれませんがこのブログも度々不正アクセスのターゲットにされているようでおかしなアクセスは毎日発生しています。そのため、また何かしらの攻撃を受けていたのだろうと考えてアクセスログ等確認していたのですが今回アクセスができなくなるほどの事象に発展していたのは少し事情が違ったので調査の過程と結果を残しておきます。
サーバーの起動状況の確認
最初に確認したのはサーバーの起動状況です。Webブラウザでのアクセスはできなかったのですが、sshでログインすることはできました。
また、WebサーバーやDBが起動していることもコマンドで確認できました。(このblogはAWS Lightsailで立ててます)
$ sudo /opt/bitnami/ctlscript.sh status
apache already running
mariadb already running
php-fpm already runningメトリクスの確認
起動してるのにブラウザでアクセスできないので、次の確認はCPU等のリソースの状況です。
こちらはAWSのコンソールで確認します。CPU使用率を見ると15:30頃から急上昇してバーストし、クレジットをつか切ったあたりで10%にキャップされているのが確認されました。
アクセスログの確認
つぎはどうせまた誰かが連続アクセスしているのだろう、と思ったので以下の場所にアクセスログを確認しました。
/opt/bitnami/apache2/logs/access_log
/opt/bitnami/apache2/logs/error_log
実際、攻撃と見られるアクセスは大量に見つかりましたが、ただ、このCPUリソースを枯渇させるほどアクセスが集中しているということはありませんでした。エラーは確かに増えていますがこれは原因と結果が逆でCPUが枯渇したからそうなってるものです。
CPUを利用しているリソースの確認
$ top コマンドを用いて確認しました。結果は mysqld (MySQL)プロセスがCPU使用率151%を占有していました。
実行中のクエリを調べる
MySQLが原因なのがわかったので次は実行中のクエリを調べます。MySQLに入って次のクエリを打ちます。
SHOW FULL PROCESSLIST;
Time が大きいものを調べます。ブログにアクセスが続いていたので多くのクエリが詰まっているのが確認できました。
その中で、 wp_aiowps_audit_log というテーブルへのDELETE文がクエリ詰まりの原因になっているのがわかりました、
この wp_aiowps_audit_log はこのブログで使っているセキュリティプラグインの監査ログです。
どうも、ある日莫大な量の不正アクセスを受け、この監査ログが数十万レコード規模の大きなテーブルになっていたようです。そして古いものを消すDELETE処理に時間がかかるようになったというのが今回のCPU枯渇の原因でした。
対応1 巨大になった監査ログテーブルのレコードを削除する
不正アクセスは間接的な原因で、不正アクセスの監査ログの扱いが直接的な問題となってアクセスができなくなっていたことがわかったので対応しました。
一つはdeleteを効率化するためのindexの設定です。
SHOW INDEXES FROM wp_aiowps_audit_log;
を使ってインデックスを確認したところ、削除対象を決めるのに使っていた created 列にインデックスがないことがわかったので作成しました。
ALTER TABLE wp_aiowps_audit_log ADD INDEX idx_created (created);
続いて、莫大になってしまったレコードの削除です。一回でDELETEしようとするとバッチが行ったのと同じように止まってしまっていたので、小分けに消しました。
-- 1回に5000件ずつ削除
DELETE FROM wp_aiowps_audit_log
WHERE created < UNIX_TIMESTAMP(DATE_SUB(NOW(), INTERVAL 7 DAY))
LIMIT 5000;DELETE文に LIMIT が使えるというのを今回初めて知りました。
削除対象が0になるまでこれを何度も発行しました。
対応2 XML-RPC経由のアクセスをブロックする
さて、こちらがセキュリティ面の本対応です。
このブログはログインページのURLをデフォルトから変えていて、通常は辿り着けず、ログインを試行することもできないようにしています。それでも今回不正ログインを試みた監査ログが数十万単位で発生したのは、XML-RPC 経由でのログインを試みられていたからでした。
幸い、All-in-One WP Security のファイアウォール設定でブロックできるので今回からブロックすることしました。
これでおそらく今回の事象は解決したんじゃないかなと思います。
これはこれとして、数々の攻撃を受けているのは確かなので不正なアクセス検知やIPアドレス指定してのブロック等々可能な対応は順次進めていこうと思います。