Aurora 3.04.2 での DDL の予期しない挙動と Rails での対策

こんにちは、DBRE (Database Reliability Engineer) の shinta です。

今回は、Aurora 3.04.2 に存在する DDL の予期しない挙動について紹介したいと思います。

発見のきっかけ

きっかけは、Aurora 3.04.1 に存在した以下の事象の検証でした。（CyberAgent 様の記事で事象の存在を知り、検証するに至りました。ありがとうございます！）

これがどんな事象かというと、「ALGORITHM=INPLACE で特定の online DDL を実行している間、そのテーブルに reader からアクセスできなくなる」というものでした。

writer で DDL を実行している間、reader からそのテーブルにクエリを投げると以下のエラーが出ます。

Table 'db_name.tbl_name' doesn't exist

弊社でも検証をした結果、以下の DDL について事象が再現することが分かりました。（一例です）

カラムの削除 DROP COLUMN
カラムに NULL を許容する・しない MODIFY COLUMN xxx NULL/NOT NULL
あるカラムの後にカラムを追加 ADD COLUMN xxx AFTER yyy
テーブルのデフラグ OPTIMIZE TABLE

事象の再現した DDL について、いずれも ALGORITHM = INPLACE かつテーブルの再構築が必要な online DDL という共通点が見られました。

MySQL :: MySQL 8.0 リファレンスマニュアル :: 15.12.1 オンライン DDL 操作

Aurora のリリースノートによると、この現象は Aurora 3.04.2 で修正が施されたとのことでした。そのため、弊社でその修正状況を検証で再確認したところ、reader からテーブルが開けない事象が Aurora 3.04.2 上でも確認できました。

docs.aws.amazon.com

reader からテーブルが開けなくなる事象が発覚して以降、弊社の中でも DDL を実行する際の運用手順が複雑になっていたため、Aurora 3.04.2 は念願のアップデートでした。しかし、事象が再現してしまったため、再度社内で検証・調査したところ、事象の再現条件が判明しました。

事象の再現条件

仮に、Aurora 3.04.1 で事象が起きていた DDL の集合を「問題の DDL」と呼ぶことにします。以下の条件で発生するようです。

1a: そのテーブルへ問題の DDL が実行されてから、reader 経由でそのテーブルへアクセスされていない
1b: そのテーブルが作成されてから、reader 経由でそのテーブルへアクセスされていない
2: 1a か 1b が満たされている状態で、問題の DDL をそのテーブルへ実行する
3: DDL 実行中に reader からそのテーブルへアクセス → テーブルが開けない事象発生

Aurora 3.04.1 と比べて、事象の発生条件に 1a / 1b の条件が追加されています。

この事象の発生可能性

整理すると、この事象の発生する状況とは以下のような状況です。時系列で並んでいると思ってください。

前回 DDL 実行後から、reader からそのテーブルへはアクセスのない状況
テーブルに問題の DDL を流す (ex. DROP COLUMN など)
DDL 実行中に、初めて reader からそのテーブルへアクセスされる → テーブルが開けない事象が起きる

今までそのテーブルにアクセスがなかったのに、DDL 実行中にたまたま初めてアクセスがあるということがあるのでしょうか？？ DDL の実行時間は大抵は数秒以内に終わるものがほとんどです。

我々はこの事象は現実的には起きる可能性は極めて低いと考え、開発者に提供している DDL の実行基準をこの事象が起きない前提で書き直しました。

そして本番環境で発生

発生しないと考えていたこの事象が本番環境で発生しました。発生条件が間違っていたのか...? 低い確率に当たってしまったのか...? と最初は考えましたが、それ以外で発生する状況が存在しました。

それは、問題の DDL が連続で実行された時です。

実際の状況

弊社はプロダクト開発では主に Ruby on Rails を使って開発しているのですが、実際に事象の発生した migration ファイルがこちらになります。（カラム名などは実際のものではありません）

class AllowColumnsNullOnTblName < ActiveRecord::Migration[7.0]
  def change
    change_table :tbl_name, bulk: true do |t|
      t.change_null :xxx_id, true
      t.change_null :yyy_id, true
    end
  end
end

あるテーブルに対して、カラムを二つ null を許容するようにする migration ファイルです。カラムから NOT NULL 制約を外すのは ALGORITHM=INPLACE で実行される && テーブルの再構築が必要な online DDL なので、問題の DDL に該当します。
bulk: true オプションは後述しますが効果がなかったので、時系列的には以下の事象が発生していました。

reader からテーブル tbl_name へはアクセスがある状態
ALTER TABLE tbl_name MODIFY COLUMN xxx_id NULL, ALGORITHM=INPLACE が実行される
続けて ALTER TABLE tbl_name MODIFY COLUMN yyy_id NULL, ALGORITHM=INPLACE が実行される
2 と 3 の間に reader から tbl_name へアクセスがないので、再現条件の 1a 「そのテーブルへ問題の DDL が実行されてから、reader 経由でそのテーブルへアクセスされていない」を満たし、3 の DDL 実行中は tbl_name にアクセスできないエラーが発生する

我々が同じテーブルへ問題の DDL が連続で実行された場合のことを考慮できていなかったため発生した事象でした。

なぜ bulk オプションが効かなかったのか

以下は bulk: true を指定した時の change_table のコードですが、migration に対して #{command}_for_alter というメソッドがある場合にまとめて実行されるようです。

rails/activerecord/lib/active_record/connection_adapters/abstract/schema_statements.rb at v7.0.7.1 · rails/rails · GitHub

MySQL の場合は以下の 9 つのメソッドがあり、ここに対応づけられなかった場合 bulk で実行されないようでした。

add_column_for_alter
remove_column_for_alter
remove_columns_for_alter
add_timestamps_for_alter
remove_timestamps_for_alter
add_index_for_alter
remove_index_for_alter
change_column_for_alter
rename_column_for_alter

おそらく t.change_null という書き方が良くなかったのではと思い、事象が発生した migration ファイルを以下のように書き直したところ DDL がまとまるのを確認できました。

変更前

class AllowColumnsNullOnTblName < ActiveRecord::Migration[7.0]
  def change
    change_table :tbl_name, bulk: true do |t|
      t.change_null :xxx_id, true
      t.change_null :yyy_id, true
    end
  end
end

D, [2024-07-05T01:53:51.555089 #559] DEBUG -- :    (39.4ms)  ALTER TABLE `tbl_name` CHANGE `xxx_id` `xxx_id` bigint DEFAULT NULL
D, [2024-07-05T01:53:51.588536 #559] DEBUG -- :    (32.0ms)  ALTER TABLE `tbl_name` CHANGE `yyy_id` `yyy_id` bigint DEFAULT NULL
   -> 0.0857s

変更後

class AllowColumnsNullOnTblName < ActiveRecord::Migration[7.0]
  def change
    change_table :tbl_name, bulk: true do |t|
      t.change :xxx_id, :bigint, null: true
      t.change :yyy_id, :bigint, null: true
    end
  end
end

D, [2024-07-04T09:08:41.729692 #518] DEBUG -- :    (43.9ms)  ALTER TABLE `tbl_name` CHANGE `xxx_id` `xxx_id` bigint DEFAULT NULL, CHANGE `yyy_id` `yyy_id` bigint DEFAULT NULL
   -> 0.0560s