Rails CIが同時に複数モジュールで落ちたときの対応方法 Yasuo Honda @yahonda GinzaRails#38 Oct 2

話すこと たまに落ちるRailsのCIを直したり、再現状況を絞り込んだりしてきた CI failureを修正するpull requestでは、解決された結果(うまくいった)ことを記述してい る 今回は、それらに書かれていない(書く必要のない)、解決に至るまでに何を考えて、どの ようなことをしたのかを説明します

前提知識としてのRails CIの特色 BuildKiteを利用　https://buildkite.com/rails/rails/builds?branch=main Gemfile.lock はリポジトリにあるが、CI時に削除して、 bundle install している https://github.com/rails/buildkite- config/blob/ed61405b4b52f480a49e3556ccc50ce0dcbda31d/Dockerfile#L134 && rm Gemfile.lock && bundle install -j 8 && cp Gemfile.lock tmp/Gemfile.lock.updated \ Dependabot などによるGemfile.lockの更新は行われていない 定期的にRafaelが Gemfile.lock のバージョンを一括で上げている AciveRecordで利用されるRDBMSは下記のDockerイメージを利用 PostgreSQL:　 postgres:alpine MySQL: mysql:latest

2021年10月4日頃 - Rails CIのjobが赤くなっている https://buildkite.com/rails/rails/builds/81481

その直前のCIはgreen https://buildkite.com/rails/rails/builds/81423

Failしているモジュール3つ Railties (railties) Active Record PostgreSQL (activerecord postgresql) Active Job integration (acivejob integration)

Railties https://buildkite.com/rails/rails/builds/81481#a7c8033a-6e08-401c-9abd- 131a339b8775/1136-1164 Controller周り Failure: ScaffoldControllerGeneratorTest#test_controller_tests_pass_by_default_inside_full_engine [test/generators/scaffold_controller_generator_test.rb:256]: Expected /2 runs, 2 assertions, 0 failures, 0 errors/ to match "Run options: --seed 38355 # Running: .E Error: DashboardControllerTest#test_should_get_foo: ActionController::MissingExactTemplate: DashboardController#foo is missing a template for request formats: text/html /rails/actionpack/lib/action_controller/metal/implicit_render.rb:45:in `default_render' /rails/actionpack/lib/action_controller/metal/basic_implicit_render.rb:6:in `block in send_action' /rails/actionpack/lib/action_controller/metal/basic_implicit_render.rb:6:in `tap' /rails/actionpack/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action' /rails/actionpack/lib/abstract_controller/base.rb:214:in `process_action' /rails/actionpack/lib/action_controller/metal/rendering.rb:53:in `process_action' /rails/actionpack/lib/abstract_controller/callbacks.rb:234:in `block in process_action' /rails/activesupport/lib/active_support/callbacks.rb:118:in `block in run_callbacks' /rails/actiontext/lib/action_text/rendering.rb:20:in `with_renderer' ... snip ... /rails/actionpack/lib/action_dispatch/testing/integration.rb:279:in `process' /rails/actionpack/lib/action_dispatch/testing/integration.rb:16:in `get' /rails/actionpack/lib/action_dispatch/testing/integration.rb:370:in `get' /rails/railties/test/fixtures/tmp/bukkits/test/controllers/dashboard_controller_test.rb:5:in `block in ' rails test test/controllers/dashboard_controller_test.rb:4 Finished in 0.180352s, 11.0894 runs/s, 5.5447 assertions/s. 2 runs, 1 assertions, 0 failures, 1 errors, 0 skips

CIが落ちる理由として考えたこと 1. このcommitそのものによるものか Pull request https://github.com/rails/rails/pull/43335 に対して実施されたCIは greenなので考えにくい committerによるmain branchへの直接pushでは、事前にCIが回らないためありえ る 2. テストの順序依存によるものか すべてのRubyバージョンで問題が起きており、テスト順序依存とは考えにくい テストの順序依存問題については、大体対応できているので可能性は低そう 3. そのほかの環境変化によるものか 今回はこちらに該当する

「そのほかの環境変化によるもの」の絞り込み "Rails CIの特色"を思い出してみる bundle install だと再現しない rm Gemfile.lock ; bundle install だと再現する 利用している Gemfile.lock の違いだろうと範囲が絞り込まれる

利用している Gemfile.lock の違い: 7 gems updated Last successful build aws-partitions (1.507.0) cssbundling-rails (0.2.3) debug (1.1.0) jsbundling-rails (0.1.8) selenium-webdriver (4.0.0.rc1) sequel (5.48.0) tailwindcss-rails (0.4.3) First failing build aws-partitions (1.509.0) cssbundling-rails (0.2.4) debug (1.2.2) jsbundling-rails (0.1.9) selenium-webdriver (4.0.0.rc2) sequel (5.49.0) tailwindcss-rails (0.5.0)

7つのgemの更新により事象が再現するか確認する bundle update --conservative で Gemfile.lock で違いのあったgemのみ 更新する $ bundle update aws-partitions cssbundling-rails debug jsbundling-rails \ selenium-webdriver sequel tailwindcss-rails --conservative https://bundler.io/man/bundle-update.1.html Use bundle install conservative update behavior and do not allow indirect dependencies to be updated. 7つのgemをupdateすると、事象が再現した

7つのgemのどれがきっかけになっているか絞り込む 機械的にやるなら3:4に分割して bundle update --conservative 今回は、Rails 7の新しいgem3つ cssbundling-rails , jsbundling-rails , tailwindcss-rails のみを更新して再現した さらに3つのgemを一つずつ試すと...

tailwindcss-rails のみの更新で事象が再現した 最小再現ケース cd railties bundle update --conservative tailwindcss-rails git diff bin/test test/generators/scaffold_controller_generator_test.rb:248 git diff rails (>= 6.0.0) sucker_punch (3.0.1) concurrent-ruby (~> 1.0) - tailwindcss-rails (0.4.3) + tailwindcss-rails (0.5.0) rails (>= 6.0.0) terser (1.1.4) execjs (>= 0.3.0, < 3)

tailswindcss-railsのどのcommitで振る舞いが変わったのか tailwind-css-rails 0.4.3 と 0.5.0 の間のいずれかのcommitがきっかけになって いるはず tailwindcss-rails の main ブランチで再現を試みる -> 再現しない gem "tailwindcss-rails", github: "rails/tailwindcss-rails", branch: "main" 0.5.0 と main の間のcommitで対応されたと考えられる https://github.com/rails/tailwindcss-rails/pull/78 でmainブランチには修正されていた tailwindcss-rails 0.5.1 をリリースしてもらって対応終了 https://rubygems.org/gems/tailwindcss-rails/versions/0.5.1 Gemfile.lock の tailwindcss-rails (0.4.3) はそのまま(理由は前述したとおり)

第一部終わり

Active Record PostgreSQL (activerecord postgresql) https://buildkite.com/rails/rails/builds/81481#a9f5a3f2-46a2-44f2-a9b4- ca15516e04cb/1099-1110 Failした結果の抜粋 ActiveRecord::Schema.define(version: 0) do ... snip ... # Custom types defined in this database. # Note that some types may not work with other database engines. Be careful if changing database. create_enum "mood", ["happy", "ok", "sad"] end create_enum メソッド第2引数のarray要素の順序が違う assert output.include?('create_enum "mood", ["sad", "ok", "happy"]'), output

CIが落ちる理由として考えられること(ふたたび) 1. このcommitそのものか Pull requestはAction Packのものなのでまず関係ない 2. テストの順序依存によるものか すべてのRubyバージョンで出ているので関係ない 3. そのほかの環境変化によるものか 今回も「そのほか」だろう

「そのほかの環境変化によるもの」の絞り込み(ふたたび) 2021年9月30日にPostgreSQL 14がリリースされた https://www.postgresql.org/about/news/postgresql-14-released-2318/ また"Rails CIの特色"を思い出してみる BuildKiteに利用しているDockerイメージは、最新のPostgreSQLに追随する ということは...

PostgreSQLのDockerイメージでPostgreSQL 13を明示してみる PostgreSQL 13では、エラーが再現しないことを確認した https://github.com/rails/buildkite-config/pull/14 @@ -109,7 +109,7 @@ services: - "./mysql-initdb.d:/docker-entrypoint-initdb.d" postgres: - image: "${POSTGRES_IMAGE-postgres:alpine}" + image: "${POSTGRES_IMAGE-postgres:13}" environment: POSTGRES_HOST_AUTH_METHOD: "trust"

修正コード 修正は、jhawthorn によるもの string_agg 関数の中で enumsortorder で明示的に order by するように変更 https://github.com/rails/rails/pull/43371/files query = <<~SQL SELECT type.typname AS name, - string_agg(enum.enumlabel, ',') AS value + string_agg(enum.enumlabel, ',' ORDER BY enum.enumsortorder) AS value FROM pg_enum AS enum JOIN pg_type AS type ON (type.oid = enum.enumtypid) これでこのテストはgreenとなった 背景をもう少し見てみましょう

SQL文での再現コード DROP TYPE IF EXISTS mood; DO $$ BEGIN IF NOT EXISTS ( SELECT 1 FROM pg_type t WHERE t.typname = 'mood' ) THEN CREATE TYPE "mood" AS ENUM ('sad', 'ok', 'happy'); END IF; END $$; SELECT type.typname AS name, string_agg(enum.enumlabel, ',') AS value FROM pg_enum AS enum JOIN pg_type AS type ON (type.oid = enum.enumtypid) GROUP BY type.typname;

PostgreSQL 13での結果 : sad,ok,happy activerecord_unittest=# SELECT type.typname AS name, string_agg(enum.enumlabel, ',') AS value FROM pg_enum AS enum JOIN pg_type AS type ON (type.oid = enum.enumtypid) GROUP BY type.typname; name | value ------+-------------- mood | sad,ok,happy (1 row)

PostgreSQL 14での結果 : happy,ok,sad activerecord_unittest=# SELECT type.typname AS name, string_agg(enum.enumlabel, ',') AS value FROM pg_enum AS enum JOIN pg_type AS type ON (type.oid = enum.enumtypid) GROUP BY type.typname; name | value ------+-------------- mood | happy,ok,sad (1 row)

PostgreSQL 13.4での実行計画 activerecord_unittest=# explain activerecord_unittest-# SELECT type.typname AS name, string_agg(enum.enumlabel, ',') AS value FROM pg_enum AS enum JOIN pg_type AS type ON (type.oid = enum.enumtypid) GROUP BY type.typname; QUERY PLAN ----------------------------------------------------------------------------------------- GroupAggregate (cost=130.53..148.08 rows=780 width=96) Group Key: type.typname -> Sort (cost=130.53..132.48 rows=780 width=128) Sort Key: type.typname -> Hash Join (cost=73.20..93.06 rows=780 width=128) Hash Cond: (enum.enumtypid = type.oid) -> Seq Scan on pg_enum enum (cost=0.00..17.80 rows=780 width=68) -> Hash (cost=58.09..58.09 rows=1209 width=68) -> Seq Scan on pg_type type (cost=0.00..58.09 rows=1209 width=68) (9 rows)

PostgreSQL 14.0での実行計画 : Sort 処理が消えている activerecord_unittest=# explain activerecord_unittest-# SELECT type.typname AS name, string_agg(enum.enumlabel, ',') AS value FROM pg_enum AS enum JOIN pg_type AS type ON (type.oid = enum.enumtypid) GROUP BY type.typname; QUERY PLAN -------------------------------------------------------------------------------- HashAggregate (cost=75.85..76.82 rows=78 width=96) Group Key: type.typname -> Hash Join (cost=2.75..75.26 rows=78 width=128) Hash Cond: (type.oid = enum.enumtypid) -> Seq Scan on pg_type type (cost=0.00..67.71 rows=1071 width=68) -> Hash (cost=1.78..1.78 rows=78 width=68) -> Seq Scan on pg_enum enum (cost=0.00..1.78 rows=78 width=68) (7 rows)

わかっていること・わかっていないこと RDBMSでは、 order by のないクエリーの結果順序は「不定(non determistic)」である PostgreSQL 13でも「並び順はデフォルトでは指定されません」と書いてある https://www.postgresql.jp/document/13/html/functions-aggregate.html 集約関数(中略)string_agg、およびxmlagg、そして類似のユーザ定義の集約関数 は、入力値の順序に依存した意味のある別の結果値を生成します。 この並び順はデ フォルトでは指定されませんが、4.2.7に記述されているように、集計呼び出し中 にORDER BY句を書くことで制御可能となります。 PostgreSQL 14 Beta 2(2021年6月24日)の時点で再現することがわかった https://www.postgresql.org/about/news/postgresql-14-beta-2-released-2249/ PostgreSQL 13から14の間のどのcommitによる振る舞いの変更なのかはわからなかった PostgreSQLのコードをgit bisectしてビルドすれば理論上可能のはず

第二部終わり

Active Job integration (acivejob integration) Integration testに必要なPostgreSQLデータベースが存在しない NOTICE: database "active_jobs_qc_int_test" does not exist, skipping Cannot run integration tests for queue_classic. To be able to run integration tests for queue_classic you need to install and start postgresql.

修正コード by jhawthorny(again) 修正はRailsのActive Job integration testが利用している queue_classic になされた https://github.com/QueueClassic/queue_classic/pull/334 libpqに渡す接続文字列でttyオプションの値を空文字 '' から nil に変更している [ host, # host or percent-encoded socket path url.port || 5432, - nil, '', #opts, tty + nil, nil, #opts, tty url.path.gsub("/",""), # database name url.user, url.password Rails側ではこのpull requestの元になるブランチのqueue_classicを利用中 https://github.com/rails/rails/pull/43373

この変更が必要なわけ "PostgreSQL 14 tty"で検索したところ、"篠田の虎の巻「PostgreSQL 14 新機能検証結 果」"に乗っていそうなことがわかった https://community.hpe.com/t5/HPE-Blog-Japan/篠田の虎の巻-PostgreSQL-14-GA-新 機能検証結果-公開/ba-p/7151317#.YXgEyZ-RX0p 2.5.13. LIBPQ 接続文字列 接続文字列の authtype および tty は削除されました。SSL 圧縮を行うクライアン ト接続 設定 sslcompression はバックエンドでは無視されます。 当時は、ダウンロードできなかったので、twitterで聞いたところ、なんと該当する commitまで教えていただきました https://twitter.com/nori_shinoda/status/1445278813311561728 (そのときはBeta版で、GA版に移行する前だったのでダウンロードできなかった)

この変更が有用なわけ (cont.) 「接続文字列の authtype および tty は削除されました。」のcommit https://github.com/postgres/postgres/commit/14d9b37607ad30c3848ea0f2955a7 8436eff1268 2003年(PostgreSQL 7.4)からdeprecatedになったったttyオプションが、約18年たって PostgreSQL 14で削除された https://github.com/postgres/postgres/commit/cb7fb3ca958ec8bd5a14e740c067f1d 096af3454 https://github.com/QueueClassic/queue_classic/pull/334 は動くことはわかったが、 この根拠があったほうがマージされやすいと考えたため、追記してコメント https://github.com/QueueClassic/queue_classic/issues/333#issuecomment- 934200173 無事pull requestがマージされる

第三部終わり - All set.

まとめ 一度に複数のfailuresがあっても、ひとつずつ直していけば、そのうちに直ります 振る舞いを変える複数のソフトウェア(gemだったりデータベースだったり)が、同じタ イミングでリリースされることもあります RailsのCIの特色を知り、Railsにpull requestをだしたときのCIが赤くなったときにも役 立ててください