この記事は GMOインターネットグループ Advent Calendar 2024 6日目の記事です。こんにちは。GMOペパボ株式会社のyumuです。先日、当社のサービスであるminneが約15分間にわたって利用できなくなるインシデントが発生しました。きっかけは一見単純なデータベースマイグレーションの実行でしたが、偶然同じタイミングで動いていた重いクエリとの競合により、MySQLへの新規接続が次々とタイムアウトしてしまいました。本記事では、このインシデントがどのように発生し、それにMySQLのロック機構がどう影響していたのか、そして同じ問題を繰り返さないためにどのような対策を行ったのかについて解説していきます。なお、本記事で説明する内容は、minneで使用しているMySQL 8.0を前提としています。
インシデント発生から原因特定までの道のり
ある日の午後、Slackに突如として大量のエラー通知が流れ始めました。
ActiveRecord::AdapterTimeout
Mysql2::Error::TimeoutError: Timeout waiting for a response from the last query.
MySQLへの接続がタイムアウトしているようです。このエラー自体は時々見かけるものですが、今回は明らかに様子が違います。通知の量が尋常ではなく、minneへのアクセスが全くできなくなってしまっていました。
原因を探るため、まずは直近の変更内容を確認します。すると、ちょうどその時間にデータベースマイグレーションを実行していたことが分かりました。しかし、マイグレーションの内容自体はそれほど複雑なものには見えません。
Mackerel(サーバーやアプリケーションの監視サービス)の監視画面を確認すると、MySQLのDisk IOPSのreadと接続数が急上昇していました。しかし、その後、監視データ自体が取得できなくなってしまっています。監視サービスもMySQLに接続できなくなってしまったようです。
手がかりを求めて、MySQLのスロークエリログを確認することにしました。そこで興味深い発見がありました。
# Query_time: 1383.272262 Lock_time: 0.000002 Rows_sent: 2 Rows_examined: xxx
SET timestamp=1709704141;
SELECT `users`.* FROM `users` WHERE `users`.`deleted_at` IS NULL AND `users`.`name` LIKE '%HOGE%' ORDER BY `users`.`id` desc LIMIT 30 OFFSET 0 /*controller:users,action:index*/;
なんと、あるクエリが23分以上も実行され、数千万行のレコードを走査していたのです。このクエリの完了直後にエラーが収まっていたことから、インシデントの原因としてこのクエリを疑い始めました。
調査を進めるうちに、私は「メタデータロック」という仕組みにたどり着きました。これは、テーブル構造を変更する際に使用されるロックの仕組みです。外部キー制約を追加する際は、親テーブルに対してもこのロックが必要になります。今回のマイグレーションでは、まさにこの外部キー制約の追加が含まれていたのです。
これらのことから、問題の全容が見えてきました。重いクエリの実行中にマイグレーションが走り、ロックの競合が発生。その結果、後続のクエリが待機状態となり、MySQLの接続を消費し続けた結果、ついには新規の接続が全て失敗する状態に陥ったのです。 では、具体的にどのような仕組みでこの問題が起きたのでしょうか?次章では、メタデータロックの仕組みについて詳しく見ていきます。
メタデータロックの仕組み
メタデータロックとは
データベースでは、テーブルの構造を変更する際に整合性を保つ必要があります。例えば、あるテーブルに対してSELECTを実行している最中に、別のセッションがそのテーブルの構造を変更してしまうと問題が発生する可能性があります。 メタデータロック(MDL)は、このようなテーブル構造の整合性を守るための仕組みです。MySQLは、テーブルへの操作に応じて自動的にこのロックを取得します。
2種類のロック
MDLには主に2種類あります。
共有ロック:通常のSELECTやUPDATE(DataManipulationLanguage(DML))時に使用される。複数の処理が同時に共有ロックを取得できる排他ロック:テーブル構造の変更時(DataDefinitionLanguage(DDL))に使用される。他のすべてのロックと競合する
外部キー制約とMDL
DDLが外部キー制約を追加する際には、制約を追加するテーブルだけでなく、参照先のテーブルに対してもMDLが必要になります。
例えば以下のような外部キー制約を追加する場合、
hogesテーブルの排他ロックusersテーブル(参照先)の排他ロック
の両方が必要になります。
ALTER TABLE hoges
ADD FOREIGN KEY (user_id) REFERENCES users(id);
実際に、ローカル環境でこの動きを確認してみました。
-- ターミナル1: トランザクションを開始し、usersテーブルへの共有ロックを取得
mysql1> BEGIN;
mysql1> SELECT * FROM users;
mysql1> SELECT * FROM performance_schema.metadata_locks\G
*************************** 1. row ***************************
OBJECT_TYPE: TABLE
OBJECT_SCHEMA: development
OBJECT_NAME: users
LOCK_TYPE: SHARED_READ
LOCK_DURATION: TRANSACTION
LOCK_STATUS: GRANTED
-- ターミナル2: 外部キー制約の追加を試みる
mysql2> ALTER TABLE hoges ADD FOREIGN KEY (user_id) REFERENCES users(id);
-- ターミナル1: processlistで確認すると、ALTER TABLEが待機状態であることが分かる
mysql1> SHOW PROCESSLIST;
(省略)
| 144 | root | localhost | development | Query | 34 | Waiting for table metadata lock | ALTER TABLE hoges ADD CONSTRAINT ...
-- ターミナル3: usersテーブルに対するクエリを試みる
mysql3> SELECT * FROM users;
-- ターミナル1: processlistで確認すると、DMLも待機状態であることが分かる
mysql1> SELECT * FROM performance_schema.metadata_locks\G
(省略)
| 107 | root | localhost | development | Query | 4 | Waiting for table metadata lock | SELECT * FROM users
| 144 | root | localhost | development | Query | 34 | Waiting for table metadata lock | ALTER TABLE hoges ADD CONSTRAINT ...
このように、既存のトランザクションが保持している共有MDLにより、外部キー制約を追加するALTER TABLE文が待機状態になり、さらにそれ以降のusersテーブルに対するDMLも待機状態になることが確認できました。
次の章では、これらの知識を踏まえた上で、今回のインシデントで実際に何が起きていたのかを詳しく説明します。
インシデントの詳細分析
実行されていた処理の詳細
まず、関連するテーブルの構造を見てみます。
usersテーブル構造
column_namedata_typeis_nullabledescriptionidintNO主キーemailvarchar(255)NOメールアドレスnamevarchar(255)YESユーザー名deleted_atdatetimeYES論理削除用のタイムスタンプ………その他カラムは省略
インデックス
index_nameis_uniquecolumn_namePRIMARYTRUEidindex_users_on_emailTRUEemailindex_users_on_nameTRUEname
このテーブルに対して、社内向けの管理画面から以下のような検索クエリが発行されました。
SELECT * FROM users
WHERE deleted_at IS NULL
AND name LIKE '%HOGE%'
ORDER BY id desc
LIMIT 30 OFFSET 0;
一見シンプルに見えるこのクエリですが、実際には数千万行あるusersテーブルをフルスキャンする重い処理でした。これには大きく分けて2つの理由があります。
1つ目は、nameカラムに対する検索方法です。nameカラムにはインデックスが設定されているものの、LIKE '%キーワード%'という中間一致での検索では、B-Treeインデックスの構造上インデックスを効果的に使用することができません。前方一致(LIKE 'キーワード%')であればインデックスが活用できますが、中間一致や後方一致(LIKE '%キーワード')の場合は、結局すべての行を走査する必要があります。
2つ目は、論理削除です。usersテーブルは論理削除を採用しているため、時間とともにレコード数が増え続けていました。その結果、インデックスが効果的に機能しない中間一致のLIKE検索が、膨大な数のレコードに対して実行されることになったのです。
一方、この重いクエリが実行されている最中に、以下のマイグレーションが実行されました。
class AddUserIdToHoges < ActiveRecord::Migration[7.0]
def change
add_column :hoges, :user_id, :integer, null: false
add_foreign_key :hoges, :users, column: :user_id, name: 'index_hoges_on_user_id'
end
end
まだ使用されていないhogesテーブルに対するマイグレーションですが、user_idに対する外部キー制約を追加したことにより、usersテーブルに対する排他MDLが必要になりました。
事態の推移
時系列で見ると、事態は以下のように進行しました。
管理画面でのユーザー検索により、重い検索クエリがusersテーブルの共有MDLを取得その途中でマイグレーションが実行され、usersテーブルの排他MDLを要求既存の共有MDLが解放されるまで待機状態にこの間、新規のクエリも全て待機状態となるMySQLの接続が次々と消費され、ついには上限に到達監視サービスを含む全ての新規接続がタイムアウト
このように、単純な検索とマイグレーションの組み合わせが、思わぬ形でサービス全体に影響を及ぼすことになりました。
再発防止に向けて
このインシデントの経験から、私たちは複数のレイヤーでの対策を進めました。
マイグレーション実行前の安全確認の徹底
まず取り組んだのは、マイグレーション実行前の確認プロセスの整備です。次のSQLを使用することで、現在のロック待ちの状態を確認できます。
SELECT * FROM performance_schema.metadata_locks;
特に外部キー制約を追加する場合は、関連するテーブルの状態確認が重要です。このクエリを実行することで、実行中の重いクエリを事前に検知し、マイグレーションのタイミングを適切に判断できます。
管理画面の改善
今回の重いクエリは管理画面から実行されたものでした。調査の結果、管理画面では「%」を使用したLIKE検索が多用されており、これが非効率なテーブルスキャンを引き起こしていることがわかりました。
そこで以下の対策を実施しました。
管理画面での曖昧検索の制限検索条件の最適化(インデックスが効くように)
監視体制の強化
また、スロークエリの監視を強化しました。AWS CloudWatchとLambdaを使い、実行時間が一定を超えるクエリを検知したらSlack通知するようにしました。これにより、潜在的なインシデントの原因に気付きやすくなり、スロークエリの改善が積極的に行われるようになりました。
データ構造の見直し
より根本的な課題として、usersテーブルの構造の見直しも検討しています。先述の通り、usersテーブルは論理削除を使用しているため、時間とともにテーブルサイズが肥大化していく一方です。長期的なプロジェクトとして、物理削除への移行を検討しています。
おわりに
一見単純なマイグレーション作業が思わぬ形でサービス停止につながった今回のインシデントですが、MySQLのロック機構について、改めて理解を深めると同時に、システム設計の基本的な部分まで見直すきっかけとなりました。
今回得られた教訓を活かし、より安定したサービス運用を目指していきます。