ActiveRecordにある便利メソッドfind_each
実装の仕方が良くなくて無限ループしてしまい、本番環境でOOM killerによって強制停止させられるという事象が発生したのでその話について書きます。
※ この記事に登場するテーブルや実装などはすべて記事用にカスタマイズしています
find_eachとは
find_eachは何をしてくれるかというと、大量のデータを一度に取得してループするのではなく決まった単位(デフォルト1,000件)ごとに取得してループしてくれます。
大量データを扱うときに一括で取得してしまうと大量のメモリを使っていしまうのですが、find_eachを使って分割して取得することで少ないメモリで処理することができます。
言葉で書いてもわかりづらいですね。下記が実行例です。
# userが1万人いる場合
pry(main)> User.all.count
(1.1ms) SELECT COUNT(*) FROM `users`
=> 10000
# eachを使うと一括で1万件取得される
pry(main)> User.all.each {|user| p user.id}
User Load (4.5ms) SELECT `users`.* FROM `users`
1
2
3
...
10000
# find_eachを使うと1,000件ずつ取得される
[8] pry(main)> User.all.find_each {|user| p user.id}
User Load (3.9ms) SELECT `users`.* FROM `users` ORDER BY `users`.`id` ASC LIMIT 1000
1
2
3
...
1000
User Load (0.8ms) SELECT `users`.* FROM `users` WHERE `users`.`id` > 1000 ORDER BY `users`.`id` ASC LIMIT 1000
1001
1002
1003
...
2000
User Load (0.8ms) SELECT `users`.* FROM `users` WHERE `users`.`id` > 2000 ORDER BY `users`.`id` ASC LIMIT 1000
2001
...
10000
詳細はRailsガイドをご覧ください。
https://railsguides.jp/active_record_querying.html#find-each
find_eachが無限ループ!!
便利メソッドfind_eachですが、最初に書いたとおり実装をミスって無限ループさせてしまいました。
無限ループになった実装を説明する前に、そもそもfind_eachはどのような仕組みで動いているのか確認します。
find_eachの仕組み
最初に載せた実行例を使ってどのように動いているのか確認します。
一番最初に発行されるSQLを見てみましょう。
SELECT `users`.* FROM `users` ORDER BY `users`.`id` ASC LIMIT 1000
limit 1000を指定して1000件取得しています。
ここで注目すべきはPRIMARY KEY(id)の昇順に並べているところです。
それでは次の1000件はどのように取得しているのでしょうか?
SELECT `users`.* FROM `users` WHERE `users`.`id` > 1000 ORDER BY `users`.`id` ASC LIMIT 1000
SQLを使って次の1000件を取得する場合はLIMITとOFFSETを使う事がよくありますが、今回のSQLにはOFFSETは使われていません。
代わりにwhere句にusers.id > 1000
という条件が増えていることがわかります。
users.id > 1000
の1000は最初に取得した1000件の最後のidが指定されています。
今回のデータはidの昇順に並んでいるため、最後のidより大きいデータを取得するという意味のusers.id > 1000
を条件に指定することでOFFSETを使わずに次の1000件を取得しています。
無限ループになる実装
無限ループが発生したfind_eachは下記のように実装されていました。
何が起きるのでしょうか?
# users.idとbooks.titleしか使わないのでselectで必要なデータのみ取得する
Book.joins(:user).select('users.id, books.title').find_each do |book|
p "user_id: #{book.id}, title: #{book.title}"
end
最初は下記のSQLが発行されます。
SELECT users.id, books.title FROM `books` INNER JOIN `users` ON `users`.`id` = `books`.`user_id` ORDER BY `books`.`id` ASC LIMIT 1000
1件目のSQLは特に問題ありません。
それでは次の1000件を取得するSQLはどうなるのでしょうか?
SELECT users.id, books.title FROM `books` INNER JOIN `users` ON `users`.`id` = `books`.`user_id` WHERE `books`.`id` > 1000 ORDER BY `books`.`id` ASC LIMIT 1000
books.id > 1000
とい条件が追加されています。条件の1000は最初に取得した1000件の最後のデータのidです。
SQLだけを見ていると気づきづらいですが、今回のSQLで取得しているidはbooks.id
ではなくusers.id
です。
そのため、books.id > 1000
に設定されている1000は最後のデータのusers.idが指定されています。
このSQLではbooks.idの昇順になっており、users.idの順序は特に制御されていません。
そのため、次の1000件目の最後のデータがbooks.id: 2000, users.id: 1
ということもありえます。
この場合、次に発行されるSQLは下記のようになります。
SELECT users.id, books.title FROM `books` INNER JOIN `users` ON `users`.`id` = `books`.`user_id` WHERE `books`.`id` > 1 ORDER BY `books`.`id` ASC LIMIT 1000
条件がbooks.id > 1
となってしまい、1つ前のSQL(books.id > 1000
)より前のデータを取得してしまいます。
このようにbooks.idの条件に順序が制御されていないusers.idが入ることで、取得するデータが前後してしまい、最悪の場合何度も同じデータを取得してしまい無限ループしてしまいます。
この問題の厄介なところは常に無限ループになるわけではなく、データによってはbooks.id > #{最後のusers.id}
がたまたまいい感じに指定されてそれっぽく完了してしまうこともあることです。
その場合、エラーにはならないけどデータが微妙におかしいという気づきづらいバグになってしまうので、無限ループになってくれたほうがマシかもしれません。
修正方法
上記の例の場合であれば、selectで取得カラムを絞らなくするとbooks.idも取得するようになるので正しく動作するようになります。
selectで取得カラムを絞る場合でも下記のようにbooks.idもきちんと取得するようにすれば正しく動作します。
Book.joins(:user).select('books.id AS id, users.id AS user_id, books.title').find_each do |book|
p "user_id: #{book.user_id}, title: #{book.title}"
end
上記の通り修正すれば修正完了ですが、今回の問題は自動テストがなかったことだと思っています。
該当の処理を通るテストはあったのですが、find_eachを2ループ以上するテストは書いていませんでした。
テストがあれば、無限ループするか結果がおかしくなるのでバグに気づけていた可能性が高いです。
これをきっかけにfind_eachが2ループ以上するテストも追加しました。
まとめ
今回のバグはfind_eachの仕組みを正しく理解していたとしても、コードレビューなど机上確認だけで気づくのは難しいと思います。
また、1000件以上になることが稀な処理であり、1000件という単位もただのプログラム上の都合なので、ブラックボックスな動作テストでも気づかれずにしばらく潜在バグとして潜んでいました。
これに事前に気づくにはどうすればよかったのかと考えると、ホワイトボックステストでfind_eachが2ループするテストをするしかないと思いました。
ホワイトボックステストを手動でワンタイム実行してももったいないので、きちんと自動テストを書いて継続的に検証できるようにしておくとよいですね。