たった1行のSELECT文でシステムを停止しかけた話

はじめに

「SELECT文なんて読み取りだけだし、大した影響ないでしょ」

そう思っていた時期が私にもありました。

今回は、Django Adminで作成した機能によって、本番システムを停止しかけた経験を共有します。

環境

• モノリス構成（Web、DB、Appが全て1つのVM上で稼働）
• MariaDB 10.x系
• Django + Django Admin

何が起きたのか

ある日、本番環境のディスク使用率が急激に上昇していることに気づきました。みるみる増加するディスク容量に心臓が止まりだったことを今でも鮮明に覚えています。
調査してみると、/tmp領域が異常な速度で肥大化していました。

原因は後から判明したのですが、Django Adminから実行された1つのSELECT文でした。

なぜ巨大なtmpファイルが生成されたのか

DjanogのORMが生成したクエリには複数の問題がありました。それが重なり、ディスクフルになりかけるほどに一時ファイルが巨大化していました。

1. インデックスが貼られていないカラム同士でJOINしていた
2. 複数テーブルの大量データをJOINしていた
3. ORDER BYによるソート処理が発生していた

MariaDBは、メモリ上で処理しきれない中間結果やソート処理を/tmpにファイルとして書き出します。インデックスのないJOINは全件スキャンとなり、その結果セットをソートするために巨大な一時ファイルが生成されてしまいました。

モノリス構成の恐ろしさ

今回の環境はモノリス構成で、Web、DB、Appが全て同一VM上で動作していました。
つまり、DBの一時ファイルがディスクを圧迫すると以下のような自体が起こることが想定できます。

• Webサーバーが動作不能に
• アプリケーションログが書けなくなる
• 最悪の場合、OS自体が不安定に

1つのSELECT文がシステム全体を道連れにするという、非常に危険な状態でした。

対応と反省

その時の対応

運良くディスク使用率の上昇に気づき、MariaDBを再起動することで事なきを得ました。
ただ、今思えばクエリをkillすれば良いだけだったので、再起動という大きな影響を与える対応を取ってしまったのは反省点です。

（以下のような形で実行中のクエリをkillすることが可能です。）

-- 実行中のクエリを確認
SHOW PROCESSLIST;
-- 上記だと長いクエリは省略されてしまうので、詳しくみたい時は以下の通り
SHOW FULL PROCESSLIST;

-- 問題のクエリをkill
KILL <process_id>;

例として、実際に簡易的にMariaDB on docker環境でクエリのkillを実施してみました。

-- 実行しているクエリの確認
SHOW PROCESSLIST;

+----+------+-----------+--------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
| Id | User | Host      | db     | Command | Time | State        | Info                                                                                                 | Progress |
+----+------+-----------+--------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+
|  8 | root | localhost | testdb | Query   |    5 | Sending data | SELECT a.*, b.*, c.* FROM test_table a, test_table b, test_table c WHERE a.value = b.value AND b.val |    0.000 |
|  9 | root | localhost | NULL   | Query   |    0 | starting     | SHOW PROCESSLIST                                                                                     |    0.000 |
+----+------+-----------+--------+---------+------+--------------+------------------------------------------------------------------------------------------------------+----------+


-- kill実行(注意 : MariaDBとインタラクティブの状態で)
KILL 8;

-- 再度実行中のクエリ確認
SHOW PROCESSLIST;

+----+------+-----------+------+---------+------+----------+------------------+----------+
| Id | User | Host      | db   | Command | Time | State    | Info             | Progress |
+----+------+-----------+------+---------+------+----------+------------------+----------+
| 11 | root | localhost | NULL | Query   |    0 | starting | SHOW PROCESSLIST |    0.000 |
+----+------+-----------+------+---------+------+----------+------------------+----------+

根本原因

• 巨大なDBに対するテストを行っていなかった
• DjangoのORMを信用しすぎていた
• 生成されるSQLを確認していなかった
• MariaDBを古いバージョンで運用していた

Django ORMは便利ですが、裏で生成されるSQLを意識しないと、思わぬパフォーマンス問題を引き起こします。
その後の開発では、ORMを信用しないのはもちろん。オプティマイザも信用しないくらいまでになりました(笑)

恒久対策

1. tmp領域の分離

MariaDB 11.5以降ではtmp_disk_usage_limitでtmp領域のサイズ制限が可能になりましたが、当時のバージョンでは対応していませんでした。

すぐにMariaDBをアップデートするのは工数的に難しかったため、MariaDBが使用するtmp領域を別パーティションに切り離すという対策を取りました。

# my.cnf
[mysqld]
tmpdir = /mnt/mariadb_tmp

これにより、仮にtmpが肥大化しても、システム全体のディスクを圧迫することはなくなりました。

2. テスト手順の最適化

テスト工程に、以下を追加し必ずORMによって生成されたSQLを確認するようにしました。

• 巨大DBのテスト環境での実行時間の確認とtmp領域の使用有無
• 実行計画(indexが貼られていないところでjoinしていないかなど)

ちなみにオプティマイザが見当違いのindexを使おうとしている時はUSE INDEX(このインデックス使うといいよ〜)やFORCE INDEX(絶対このインデックス使え！！)のように使用するインデックスを指示可能です。

(例)

SELECT * FROM table1 USE INDEX (col1_index,col2_index)
  WHERE col1=1 AND col2=2 AND col3=3;

SELECT * FROM table1 IGNORE INDEX (col3_index)
  WHERE col1=1 AND col2=2 AND col3=3;

3. SQLの可視化

2. テスト手順の最適化でSQLの実行時間を確認するという点で、audit pluginを入れていてSELECTも出力するようにすれば確認は可能ですが、面倒ではありました。そこでDjango Adminには便利なライブラリが用意されています。
以下のライブラリを使用すれば簡単に実行されているSQLの確認もできるので、ここで確認したSQLで実行時間など確認し、あとは巨大DB環境でEXPLAINするだけという簡単な方法が可能となりました。

• Django Debug Toolbar

教訓

1. ORMを信用しすぎない - 生成されるSQLは必ず確認する
2. 本番相当のデータ量でテストする - 小さなデータでは問題が顕在化しない
3. モノリス構成のリスクを理解する - 障害の影響範囲を把握しておく
4. インデックスは適切に設計する - 特にJOIN対象のカラム
5. 障害時の対応手順を整理しておく - 再起動の前にできることがある
6. リソースの分離を検討する - tmp領域の分離など、影響範囲を限定する設計
7. オプティマイザも信用しすぎない - EXPLAINで実行計画を確認する

(オプティマイザも信用しなくなった理由は他にありますが、今回は割愛します笑)

おわりに

たった1行のSELECT文でも、条件次第ではシステム全体を停止させる威力を持っています。
「読み取りだから安全」という思い込みは危険です。本番環境に対する操作は全て危険という認識は絶対に持っておきたい感覚です。

Django Adminのような便利なツールは、裏で何が起きているかを意識せずに使いがちですが、この経験以降、生成されるSQLをちゃんと見ることを心がけるようになりました。
皆さんも、ORMの裏側で何が起きているか、一度確認してみてはいかがでしょうか。