MySQLのALTER TABLEを監視するgemを作った話

1. はじめに

イタンジ株式会社の藤崎です。現在は、物件データ基盤の開発を担当しています。

今回は、弊社のとあるRailsプロダクトで使用するために作った「MySQLのALTER TABLEを監視するgem」を紹介しようと思います。

※ MySQL/MariaDBでのみ使用できます

RubyGems: https://rubygems.org/gems/mysql_alter_monitoring
ソースコード: https://github.com/akito-fujisaki/mysql_alter_monitoring

2. 背景

弊社では、「リアルタイム」不動産業者間サイト ITANDI BB や不動産賃貸仲介業向けの顧客管理システム nomad cloud といった、 不動産取引をなめらかにするためのサービスを数多く提供しています。

そしてその裏側には、お客様から提供いただいた大量の物件データを取り扱う、基盤となるプロダクトが存在します。

これは Ruby on Rails 7.0 (DBは Aurora MySQL 8.0) を利用したAPIサーバとして運用しており、私達のチームが開発・保守・運用を行っています。

しかし、レコード数が数千万のテーブルに対する「スキーマ変更(ALTER TABLE)」を伴う開発が必要な場合、その実行には30分近くかかることが多く、実行時間の見積もりが経験則になりがちでした。

これが心理的な負担となっていたため、スキーマ変更(ALTER TABLE)の進捗を知る術が必要でした。

パフォーマンススキーマを利用する

調査を進める中で、MySQLのドキュメントのパフォーマンススキーマを使用した InnoDB テーブルの ALTER TABLE の進行状況のモニタリングに記載された方法に行き着きました。

これは、MySQLサーバの様々な処理の実行を監視するための「パフォーマンススキーマ」と呼ばれるテーブルを使うことで、ALTER TABLEの進行状況を監視することができる、というものです。

まさに求めていた機能！ということで、しばらくこのプロダクト内に簡易的なスクリプトを用意して使っていました。

ということで前置きが長くなりましたが、今回紹介するものは、このスクリプトをgem化したものになります。

3. 使い方

3.1. インストール

mysql2 に依存していますので、 libmysqlclient 等のMySQLクライアントツールをインストールしてください。

その後、gemをお好きなようにインストールしてください。

rubygems.org

3.2 設定の有効化

パフォーマンススキーマを使用してALTER TABLEをモニタリングするためには、MySQLサーバの設定を有効にする必要があります。

そのためのコマンドを用意してありますので、下記の通りURLで指定するか、hostやportを個別に指定して実行してください。

※ URLの形式はmysql2://<user>:<password>@<host>:<port>で、RailsでDBのURLを指定する際と同じものを使用できます

# URLで指定する場合
$ mysql-alter-monitoring enable --url mysql2://root:pass@localhost:3306

# hostやportを個別に指定する場合
$ mysql-alter-monitoring enable --host localhost --port 3306 --user root --password pass

なお、AWSのRDSやAuroraを使用しておりパラメータグループで制御したい場合は、公式ドキュメント等を参考に各自で設定していただけますと幸いです。

docs.aws.amazon.com

3.3 ALTER TABLE を実行

時間のかかるALTER TABLE（インデックス追加など）を実行してください。

検証の場合、レコード数が100万件ほどのテーブルに対してインデックス追加を行うのが良いかと思います。

※ MySQLサーバが動作するマシンスペックによりますが、レコード数が100万件を超えたあたりから目に見えて遅くなり始める印象です

3.4 監視の実行

下記のコマンドで、監視を始めます。

# ALTERが終わるまで実行
$ mysql-alter-monitoring run --url mysql2://root:pass@localhost:3306

# ずっと実行
$ mysql-alter-monitoring run-forever --url mysql2://root:pass@localhost:3306

進行状況が下記のようなjson形式のログで出力されます。

{"progress":"46.354(%)","raw":{"THREAD_ID":526,"EVENT_ID":4,"END_EVENT_ID":null,"EVENT_NAME":"stage/innodb/alter table (merge sort)","SOURCE":"ut0stage.h:448","TIMER_START":496275975246251000,"TIMER_END":496276038311459000,"TIMER_WAIT":63065208000,"WORK_COMPLETED":10761,"WORK_ESTIMATED":23215,"NESTING_EVENT_ID":1,"NESTING_EVENT_TYPE":"STATEMENT"},"level":"INFO","timestamp":"2023-02-18 01:36:02 +0000"}

{"progress":"49.046(%)","raw":{"THREAD_ID":526,"EVENT_ID":4,"END_EVENT_ID":null,"EVENT_NAME":"stage/innodb/alter table (merge sort)","SOURCE":"ut0stage.h:448","TIMER_START":496275975246251000,"TIMER_END":496276139346459000,"TIMER_WAIT":164100208000,"WORK_COMPLETED":11386,"WORK_ESTIMATED":23215,"NESTING_EVENT_ID":1,"NESTING_EVENT_TYPE":"STATEMENT"},"level":"INFO","timestamp":"2023-02-18 01:36:03 +0000"}

...

{"message":"Event is empty","level":"INFO","timestamp":"2023-02-18 01:36:07 +0000"}
{"message":"Finish monitoring","level":"INFO","timestamp":"2023-02-18 01:36:08 +0000"}

パフォーマンススキーマから返ってくるレコードは下記のような値で、rawに含まれています。

{
  "THREAD_ID":526,
  "EVENT_ID":4,
  "END_EVENT_ID":null,
  "EVENT_NAME":"stage/innodb/alter table (merge sort)",
  "SOURCE":"ut0stage.h:448",
  "TIMER_START":496275975246251000,
  "TIMER_END":496276038311459000,
  "TIMER_WAIT":63065208000,
  "WORK_COMPLETED":10761,
  "WORK_ESTIMATED":23215,
  "NESTING_EVENT_ID":1,
  "NESTING_EVENT_TYPE":"STATEMENT"
}