Rails 7.0で追加予定のenumerate_columns_in_select_statementsを試してみる

こんにちは、最近柴犬の動画ばかり見て癒されているWebエンジニアの本間です。いいですよね、柴犬...。ああ、今日もお仕事終わったら見よう（メンタルは全く問題ないのでご安心ください）。

さて早速なのですが、y-yagiさんのブログの2021-04-17のエントリで紹介されていたpull requestで1つ気になったものがありました。

このpull request、初めは内容がよくわかりませんでした。ただ内容をよく確認すると、これまでPostgreSQLにカラム追加を行った際、たまに発生するPreparedStatementCacheExpiredエラーを抑制できることがわかりました。今回、本当に効果があるのか試してみたいと思います。

修正内容

まず今回ピックアップしたpull requestの修正内容をチェックしてみます。こちらはActiveRecordの CHANGELOG.md を見ると理解しやすいです。

ActiveRecordを使ってレコードを取得したとき、修正前のSQLは以下のようになっています。

Book.limit(5)
# SELECT * FROM books LIMIT 5

SELECTするカラムが * になっていますね。

次に今回の修正で導入されたconfigを有効にします。

# config/application.rb
module MyApp
  class Application < Rails::Application
    config.active_record.enumerate_columns_in_select_statements = true
  end
end

# or, configure per-model
class Book < ApplicationRecord
  self.enumerate_columns_in_select_statements = true
end

そして、同じようにActiveRecordを使ってレコードを取得すると、SQLが以下のように変化します。

Book.limit(5)
# SELECT id, author_id, name, format, status, language, etc FROM books LIMIT 5

SELECTするカラムが * から、全てのカラムを列挙する形に変わりました。

これがpull requestの修正内容です。この内容を見て何が嬉しいの？と思う方もいるかもしれません。確かに通常の運用では、この変更で嬉しいことはないと思います。ただ、DBのmigrationとtransactionが絡んでくると嬉しい点が見えてきます。

解決したい問題

このpull requestで解決したい問題を見ていきたいと思います。

環境の準備

とりあえず最新のrailsを使ってテストできる環境を整えます。 Docker等を使って、localでPostgreSQLが動いている状況にしたのち、ターミナルで以下のコマンドを実行していきます。

ruby -v
# => 3.0.1
rails -v
# => 6.3.1.2
psql -U postgres -p 5432 -h localhost -c 'SELECT version();'
#  => PostgreSQL ...

rails new --edge --api --database=postgresql \
  --skip-spring --skip-listen \
  enumerate_columns_in_select_statements_test
# ...

cd enumerate_columns_in_select_statements_test

vim Gemfile
# gem 'rails' の branch: '6-1-stable' を 'main' に変更
bundle

vim config/database.yml
# localのPostgreSQLに合わせて修正

rails db:create
rails g scaffold user name:string age:integer
rails db:migrate

cat << EOF > db/seeds.rb
5.times do |i|
  User.find_or_create_by!(name: "name#{i + 1}", age: i * 10)
end
EOF
rails db:seed

# users_controller.rbを修正
vim app/controllers/users_controller.rb

最後の app/controllers/users_controller.rb は以下のように修正します。エラーを発生させるにはtransactionが必要なためです。

diff --git a/app/controllers/users_controller.rb b/app/controllers/users_controller.rb
index 4e46807..3a70661 100644
--- a/app/controllers/users_controller.rb
+++ b/app/controllers/users_controller.rb
@@ -41,7 +41,9 @@ class UsersController < ApplicationController
   private
     # Use callbacks to share common setup or constraints between actions.
     def set_user
-      @user = User.find(params[:id])
+      ActiveRecord::Base.transaction do
+        @user = User.find(params[:id])
+      end
     end

     # Only allow a list of trusted parameters through.

この状態でAPIサーバーを立ち上げリクエストを投げてみます。

# 念のためスレッド数とDB connection数を1に固定
export RAILS_MAX_THREADS=1

rails s

# 別ターミナルでリクエスト投げる
curl http://localhost:3000/users/1
# => {"id":1,"name":"name1","age":0,"created_at":"2021-06-08T03:48:54.633Z","updated_at":"2021-06-08T03:48:54.633Z"}

無事、DBに保存されたデータを取得してAPIで返すことができました。また、この時ログを確認してみると実行されたSQLがわかります。

Started GET "/users/1" for ::1 at 2021-06-08 14:21:42 +0900
Processing by UsersController#show as */*
  Parameters: {"id"=>"1"}
  TRANSACTION (2.6ms)  BEGIN
  ↳ app/controllers/users_controller.rb:45:in `block in set_user'
  User Load (3.0ms)  SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2  [["id", 1], ["LIMIT", 1]]
  ↳ app/controllers/users_controller.rb:45:in `block in set_user'
  TRANSACTION (6.1ms)  COMMIT
  ↳ app/controllers/users_controller.rb:44:in `set_user'
Completed 200 OK in 20ms (Views: 0.4ms | ActiveRecord: 11.7ms | Allocations: 1535)

SELECTの後は users.* になっていますね。

問題の確認

それでは、次に解決したい問題を発生させてみます。

rails s でAPIサーバーを起動させたまま、別のターミナルで以下のコマンドを実行し users テーブルにカラムを追加してみます。

rails g migration AddBirthDateToUsers birth_date:date
# ...

rails db:migrate
# => == 20210608041256 AddBirthDateToUsers: migrating ==============================
# ...

migration直後にcurlでAPIサーバーにリクエストを送ってみます。

# 1回目は500エラー
curl http://localhost:3000/users/1
# => {"status":500,"error":"Internal Server Error","exception":"#\u003cActiveRecord::PreparedStatementCacheExpired: ERROR:  cached plan must not change result type\n\u003e",...

# 2回目以降は成功
curl http://localhost:3000/users/1
# => {"id":1,"name":"name1","age":0,"created_at":"2021-06-08T03:48:54.633Z","updated_at":"2021-06-08T03:48:54.633Z","birth_date":null}

1回目のリクエストのみPreparedStatementCacheExpiredエラーが発生し、500エラーのリクエストが返されました。

エラー時のログは以下のとおり。

Started GET "/users/1" for ::1 at 2021-06-08 14:22:08 +0900
Processing by UsersController#show as */*
  Parameters: {"id"=>"1"}
  TRANSACTION (1.6ms)  BEGIN
  ↳ app/controllers/users_controller.rb:45:in `block in set_user'
  User Load (1.9ms)  SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2  [["id", 1], ["LIMIT", 1]]
  ↳ app/controllers/users_controller.rb:45:in `block in set_user'
  TRANSACTION (1.1ms)  ROLLBACK
  ↳ app/controllers/users_controller.rb:44:in `set_user'
Completed 500 Internal Server Error in 22ms (ActiveRecord: 12.3ms | Allocations: 3118)

これが、今回解決したい問題になります。このエラーは以下の流れで発生していると考えられます。

SELECT * ... のSQLをPrepared Statementとして登録
migrationを実行
トランザクションを開始
1で登録したPrepared Statementを実行するが、登録した時と結果の型が異なる（列が追加）ためSQLレベルでエラー
PostgreSQLではトランザクション内で一度SQLレベルのエラーが発生するとROLLBACKが必要。そのため、PreparedStatementCacheExpiredをraiseする。

今回の修正が入る前だと、この問題の回避策には以下のものがありました。

エラーが発生する前に、Railsサーバーを再起動する。
ignore_columns を事前にセットし、Railsサーバー再起動までカラムの追加を無視するようにする。参考エントリ -> https://flexport.engineering/avoiding-activerecord-preparedstatementcacheexpired-errors-4499a4f961cf

参照頻度が低いテーブルであれば前者の方法でも問題ないと思いますが、参照頻度が高いテーブルだとエラーが出てしまいがちです。後者の方法を使えば対応できますが、事前にデプロイが必要だったりと作業が増えてしまう問題がありました。

解決策

上記の問題を、今回追加されるenumerate_columns_in_select_statementsを使って解決してみます。

# config/application.rb

# ...

module EnumerateColumnsInSelectStatementsTest
  class Application < Rails::Application
    # ...

    # この1行を追加
    config.active_record.enumerate_columns_in_select_statements = true
   end
 end

設定変更後、 rails sでサーバーを立ち上げます。その後、curlで正しく動くことを確認。

curl http://localhost:3000/users/1
# => {"id":1,"name":"name1","age":0,"created_at":"2021-06-08T03:48:54.633Z","updated_at":"2021-06-08T03:48:54.633Z"}

ログを見るとわかりますが、SELECTの後ろが * ではなく全てのカラムが列挙されています。

Started GET "/users/1" for ::1 at 2021-06-08 14:33:56 +0900
Processing by UsersController#show as */*
  Parameters: {"id"=>"1"}
  TRANSACTION (1.8ms)  BEGIN
  ↳ app/controllers/users_controller.rb:45:in `block in set_user'
  User Load (2.2ms)  SELECT "users"."id", "users"."name", "users"."age", "users"."created_at", "users"."updated_at" FROM "users" WHERE "users"."id" = $1 LIMIT $2  [["id", 1], ["LIMIT", 1]]
  ↳ app/controllers/users_controller.rb:45:in `block in set_user'
  TRANSACTION (2.1ms)  COMMIT
  ↳ app/controllers/users_controller.rb:44:in `set_user'
Completed 200 OK in 272ms (Views: 1.0ms | ActiveRecord: 49.0ms | Allocations: 22559)

さて、ここでmigrationを実行後、curlでリクエストを再度投げてみます。

rails db:migrate
# => == 20210608041256 AddBirthDateToUsers: migrating ==============================
# ...

curl http://localhost:3000/users/1
# => {"id":1,"name":"name1","age":0,"created_at":"2021-06-08T03:48:54.633Z","updated_at":"2021-06-08T03:48:54.633Z","birth_date":null}

なんとエラーにならなくなっています！しかも、追加されたカラムも反映されています。

ログを見るとこんな感じ。追加されたカラムがSELECT文に反映されており、エラーにもなっていません。

Started GET "/users/1" for ::1 at 2021-06-08 14:35:59 +0900
Processing by UsersController#show as */*
  Parameters: {"id"=>"1"}
  TRANSACTION (3.1ms)  BEGIN
  ↳ app/controllers/users_controller.rb:45:in `block in set_user'
  User Load (2.1ms)  SELECT "users"."id", "users"."name", "users"."age", "users"."created_at", "users"."updated_at", "users"."birth_date" FROM "users" WHERE "users"."id" = $1 LIMIT $2  [["id", 1], ["LIMIT", 1]]
  ↳ app/controllers/users_controller.rb:45:in `block in set_user'
  TRANSACTION (1.8ms)  COMMIT
  ↳ app/controllers/users_controller.rb:44:in `set_user'
Completed 200 OK in 34ms (Views: 0.4ms | ActiveRecord: 17.9ms | Allocations: 4476)

なぜエラーにならなかったなのですが、以下の流れで処理されたためと推測しています。

SELECT id, name, ... のSQLをPrepared Statementとして登録
migrationを実行
トランザクションを開始（ここまでは一緒）
1で登録したPrepared StatementとSQLが異なる（カラムが追加された）ため、新規にPrepared Statementを登録
登録時と結果の型がずれていないのでエラーにならない

enumerate_columns_in_select_statementsを使うことで、PreparedStatementCacheExpiredエラーが発生しなくなることを確認できました。

まとめ

今回、Rails 7.0で追加予定のconfigの1つ、enumerate_columns_in_select_statementsの効果を試してみました。

カラムの追加は、本来副作用が少なく気楽にできるmigrationのはずなのですが、PreparedStatementCacheExpiredエラーのため慎重に行わなければなりませんでした。それが今回追加されるconfigにより、かなり実行しやすくなったと思います。こういった、細かい改善を継続して実施していただけて本当にありがたいです。

今までカラム追加時のPreparedStatementCacheExpiredエラーに悩まされた方々は、是非enumerate_columns_in_select_statementsを使ってみましょう！

以上になります。最後までご覧いただきありがとうございました。

ユニファでは一緒に働く仲間を募集しています！よかったらこちらのページもご覧ください。 unifa-e.com

ユニファ開発者ブログ

ユニファ株式会社プロダクトデベロップメント本部メンバーによるブログです。

Rails 7.0で追加予定のenumerate_columns_in_select_statementsを試してみる

修正内容

解決したい問題

環境の準備

問題の確認

解決策

まとめ