こんにちは、インフラのテックリードをしている沼沢です。

この記事は、「あすけんの Aurora 2 → Aurora 3 へのメジャーバージョンアップ軌跡」の第3弾です。

第1弾、第2弾はこちらからお読みください。
あすけんの Aurora 2 → Aurora 3 へのメジャーバージョンアップ軌跡 (1) 絶望篇
 あすけんの Aurora 2 → Aurora 3 へのメジャーバージョンアップ軌跡 (2) 希望篇

さて、前回はデータディクショナリ不整合が解消され、いよいよメンテナンス日を待つのみというところまで漕ぎ着けましたが、ここから(やらかし含む)様々な困難に直面していきます。

1st Take

2024年9月中旬

レプリケーションを貼ったところまでは良かった。
良かったのですが、ここで私は大きなミスを犯します。
それは、「binlog 保持期間の設定を短くしすぎた」ことです。

もともと、本番稼働中のクラスタ(レプリケーションソース)側で、binlog 保持期間を最大値である 2160 (90日) に設定した状態で RDS クローンを作成していました。
その後、クローンされた Aurora クラスタに対して AWS サポートに依頼してデータディクショナリ不整合が解消され、インプレースアップグレードを実施し、レプリケーションを設定しました。

このレプリケーション設定完了時点で、クローンを作成してから8日ほど経過していました。

さて、用意していた作業手順の中には、レプリケーション設定後の “事後作業” として、binlog サイズの削減のため binlog 保持期間を短くする設定を行う手順が入っていました。
本番作業は作業手順を作成して事前にチーム内のレビューを通し、書いてあるコマンドをコピペして実行することが通例です。

この手順の中で用意していたクエリはこちらです。

CALL mysql.rds_set_configuration('binlog retention hours', 168);

この時点でお気づきの方がいるかも知れませんが解説します。

まず、CALL mysql.rds_set_configuration というクエリは、RDS にて binlog 保持期間の設定を行うストアドプロシージャです。
https://docs.aws.amazon.com/ja_jp/AmazonRDS/latest/AuroraUserGuide/mysql-stored-proc-configuring.html#mysql_rds_set_configuration

これを、2160 (90日) → 168 (7日) に変更しました。
そして先ほど「レプリケーション設定完了時点で、クローンを作成してから8日ほど経過」と書きました。

つまり、保持期間を7日にしたことで8日前の binlog が無くなってしまった のです。
同期に使う binlog が1日分消失したため、本番稼働中のクラスタのクローン作成からやり直しとなり、日程を調整したメンテナンスも中止となりました。

2nd Take

気を取り直して2回目の挑戦です。まずは以下の手順をまた1から実施していきます。

本番環境の Aurora の binlog 保持期間の 2160 に設定
本番環境の Aurora クローンを作成
クローンされた Aurora クラスタに対して、AWS にてデータディクショナリ不整合を解消
クローンされた Aurora クラスタをインプレースアップグレード
本番稼働中の Aurora とインプレースアップグレード済みのクラスタ間でレプリケーションを設定

同じ失敗をしないよう、事後作業として入れていた binlog 保持期間を短くする手順はカットしました。
上記作業と並行してメンテナンス日の再調整を行い、10月上旬での実施が決まりました。

2024年9月下旬〜 10月

さて、上記作業が終わる頃にはメンテナンス日の調整が済んでいる状態で、あとは待つだけ…のはずだったのですが、またしても問題が発生します。

レプリケーションが全然追いつかないのです。

ありがたいことにあすけんは月間で121万人以上のユーザーにご利用いただいており、この書き込みトラフィックが想定以上に多かったため、レプリカラグが減る気配がないどころか増える一方という状態となっていました。
この時はまだメンテナンス日まで2週間ほどあったため、数名のエンジニアたちを巻き込んでレプリケーションのパフォーマンスを上げることに尽力します。

その中で、一部ですが以下のような対応を実施しました。

レプリカの replica_parallel_workers を引き上げ
レプリカの binlog_format を OFF に変更
レプリカのスペックアップ

これらの対応の甲斐あって、レプリカラグはようやく減少に転じます。

しかし、時すでに遅し。

減少に転じたものの、この減少ペースでは予定していたメンテナンス日までにレプリケーションは追いつかない計算だったため、2nd Take も失敗に終わるのでした。無念。

3rd Take

2024年11月

2nd Take でレプリケーションのパフォーマンスが改善されたことで確実にラグは減少していっており、このままいけば10月末頃にはラグの解消が見えている状況でした。

ビジネスサイドとメンテナンス日の再々調整を行い、次は11月上旬での実施が決まりました。
数日だけ延長サポートに突入することにはなりましたが、これでようやくメジャーバージョンアップが完遂できる。

そんなふうに考えていた時期が私にもありました。

迎えたメンテナンス当日。
メンテナンス開始前に、念の為レプリケーションの状態を確認することにしました。
そこで目にしたのは、AuroraBinlogReplicaLag が2日ほど前から “-1” を示している光景でした。

「ラグが “-1” ってなんやねんｗ」と楽観的な気持ちで念の為調べたところで冷や汗が出ます。

https://docs.aws.amazon.com/ja_jp/AmazonRDS/latest/AuroraUserGuide/CHAP_Troubleshooting.html#CHAP_Troubleshooting.MySQL.ReplicaLag

AuroraBinlogReplicaLag メトリクスが -1 を返す場合、レプリケーションがアクティブではない可能性があります。

「レプリケーションがアクティブではない可能性があります。」

「レプリケーションがアクティブではない可能性があります。」

なん…です…と…？
すぐさまデータベースにログインし、レプリカステータスを確認します。(一部抜粋)

mysql> show replica status\G
*************************** 1. row ***************************
~~snip~~
           Replica_IO_Running: Yes
          Replica_SQL_Running: No
~~snip~~
                   Last_Errno: 1064
                   Last_Error: Coordinator stopped because there were error(s) in the worker(s). The most recent failure being: Worker 1 failed executing transaction 'ANONYMOUS' at source log mysql-bin-changelog.xxxxxx
~~snip~~
        Seconds_Behind_Source: NULL

以下略

Replica_SQL_Running が No、Seconds_Behind_Source が NULL となっており、ドキュメント通り レプリケーションは止まっていました。

何やら Worker にエラーがあったようだったので、Worker の状態を確認するため performance_schema.replication_applier_status_by_worker でエラーを確認しました。

https://dev.mysql.com/doc/refman/8.0/ja/performance-schema-replication-applier-status-by-worker-table.html

詳細は載せられませんが、幸いにも発生していたエラーはスキップ可能なエラーだったため、スキップすることで無事にレプリケーションは再開できました。