弘法も筆の誤り、あるいは、DBバックアップのリストアテストはしたほうが良い話

この記事は、GMOペパボエンジニア Advent Calendar 2023 の20日目の記事です。

先日、ニッチなバグに遭遇したので、そのことについて書こうと思います。

発端

私が所属しているチームには、以下のような GitHub Actions を利用したワークフローが存在します。(簡略化しています。)

チェックアウト。
リポジトリ管理下にあるダンプファイルを mysql:8-debian イメージで起動しているコンテナの MySQL にリストア。
MySQL を利用してギョーミー¹な処理を行い、結果を取得。この際、データベースの内容も更新される。
mysqldump コマンドでデータベースのダンプファイルを取得。
ダンプファイル含め、成果物をコミット。
その他あれこれして終了。

上記のとおり、データベースサーバを恒常的に用意するのではなく、ダンプファイルをバージョン管理下に置き、必要な際にだけデータベースコンテナにリストアして利用し、変更をコミットするといった流れになっています。

このワークフローをいつもどおり実行させていたときのことでした。とくにロジックやワークフローに変更は加えていないにも関わらず、ワークフローがエラーで停止しました。エラー箇所は、ダンプファイルをリストアする箇所で、エラー内容は以下のようなものでした。

ERROR 1062 (23000) at line 255: Duplicate entry '0' for key 'foo.PRIMARY'

どうやら主キー違反が発生してリストアが続行不能のようでした。とりあえず、ダンプファイルの内容を確認したところ、世にも奇妙な事象が発生していたのです。以下がダンプファイルの内容(抜粋)です。

CREATE TABLE `foo` (
  `id` bigint unsigned NOT NULL AUTO_INCREMENT,
  `name` varchar(50) NOT NULL,
  `memo` varchar(255) NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=4 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci;

INSERT INTO `foo` VALUES
('',1,'Alice'),
('',2,'Bob'),
('',3,'Chris');

ん？

INSERT 文の内容を見たときに目を疑ってしまいました。値の順序がカラム定義順になっておらず、ハチャメチャです。これではリストアできるはずもありません。むしろ、主キー違反になってくれて助かった感じです。もしも、順序が変わったままリストアされてしまっていたら、そっちのほうが大変そうです。

わりと急ぎのタスクに関連するワークフローだったので、なんとかする必要がありました。発生している事象から、mysqldump コマンドによって作成されるダンプファイルが異常であることは明らかであるため、その線で至急解決方法を探りました。結果として、mysqldump コマンドに--complete-insertオプションを付加することで回避できることがわかり、ひとまず事なきを得ました。--complete-insertオプションを付加すると、ダンプファイル内の INSERT 文が完全な書式のものになります。具体的には、以下のようにカラム名の指定が入ります。

INSERT INTO `foo` (`memo`,`id`,`name`) VALUES
('',1,'Alice'),
('',2,'Bob'),
('',3,'Chris');

幸いなことに、カラム名の順序は値の順序と同じ(同じようにずれた)になってくれたため、このダンプファイルを用いることでリストアを正しく完了することができました。カラム名の順序だけ定義順になってしまってたりしたら、回避にもっと時間が掛かっていたかもしれません。

原因

回避策によってしのげはしたものの、職業柄、原因を突き止めたくなります。また、原因を特定しておかないとどこで想定外の問題が発生するかわかりません。事象の内容が内容なので、なおさらです。

周囲のベテランエンジニアに、このような事象に遭遇したことがあるかどうかを聞いたりしましたが、心当たりのある人はひとりもいませんでした。私も似たような事象すら聞いたこともなく、今まで全幅の信頼を寄せていたmysqldumpコマンドでそんなことが起こるのか？とmysqldumpに原因がある可能性には懐疑的でした。なにせ、データベースのバックアップを取得するための公式ツールです。もしもバグであったなら、世界中で阿鼻叫喚な現場が発生しかねません。

でも、しばらく調べてたらバグであることがわかりました…。

以下のとおり、MariaDB のバグとして公開されているのを見つけることができました。

https://jira.mariadb.org/browse/MDEV-31836

mysqldump against MYSQL server 8 creates invalid dump

と書かれているとおり、mysqldump(実体は mariadb-dump) を使用して MySQL 8 からダンプファイルを取得する際に発生するバグとのことでした。報告されている事象も、私が遭遇した事象と同様でした。

ある日突然今回の事象が発生したのは、ワークフローで使用しているコンテナのうち、mysqldump を実行するコンテナに mariadb-client パッケージをインストールする際に、バグが含まれたバージョンがインストールされるようになったことが原因でした。念のために補足しておくと、mariadb-clientパッケージをインストールすると、mariadb-dumpコマンドにシンボリックリンクされたmysqldumpコマンドがインストールされます。

個人的には、結構派手なバグと思ったのですが、世の中でまったく話題にされていなかった理由は、発生するケースが以下のとおりニッチと思われるからです。

MariaDB 10.11, 11.0, 11.1 の mysqldump(mariadb-dump) であること。
上記を使って、MySQL 8 からダンプを取得していること。

そもそも、バックアップ方法に mysqldump を利用するような論理バックアップではなく、物理バックアップを採用している場合には関係のない話ですし、上記2点で言えば、とくに後者がニッチと思われます。おそらく、大抵の現場では、ダンプファイルを取得する際に、MySQL のダンプは MySQL(の mysqldump) で取得しているし、MariaDB のダンプは MariaDB(の mysqldump というか mariadb-dump) で取得しているのだと思います。その場合は今回の事象は発生しないです。試しに以下のような確認をしてみました。

mysqldump(mariadb-dump) で MySQL 8 から取得したダンプファイル

例のごとく壊れます。

/*!40101 SET @saved_cs_client     = @@character_set_client */;
/*!40101 SET character_set_client = utf8 */;
CREATE TABLE `foo` (
  `id` bigint unsigned NOT NULL AUTO_INCREMENT,
  `name` varchar(50) NOT NULL,
  `memo` varchar(255) NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=4 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci;
/*!40101 SET character_set_client = @saved_cs_client */;

--
-- Dumping data for table `foo`
--

LOCK TABLES `foo` WRITE;
/*!40000 ALTER TABLE `foo` DISABLE KEYS */;
INSERT INTO `foo` VALUES
('',1,'Alice'),
('',2,'Bob'),
('',3,'Chris');
/*!40000 ALTER TABLE `foo` ENABLE KEYS */;
UNLOCK TABLES;
/*!40103 SET TIME_ZONE=@OLD_TIME_ZONE */;

mysqldump(mariadb-dump) で MariaDB から取得したダンプファイル

壊れない。

/*!40101 SET @saved_cs_client     = @@character_set_client */;
/*!40101 SET character_set_client = utf8 */;
CREATE TABLE `foo` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `name` varchar(50) NOT NULL,
  `memo` varchar(255) NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=4 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_general_ci;
/*!40101 SET character_set_client = @saved_cs_client */;

--
-- Dumping data for table `foo`
--

LOCK TABLES `foo` WRITE;
/*!40000 ALTER TABLE `foo` DISABLE KEYS */;
INSERT INTO `foo` VALUES
(1,'Alice',''),
(2,'Bob',''),
(3,'Chris','');
/*!40000 ALTER TABLE `foo` ENABLE KEYS */;
UNLOCK TABLES;
/*!40103 SET TIME_ZONE=@OLD_TIME_ZONE */;

mysqldump(本家) で MySQL 8 から取得したダンプファイル

壊れない。

/*!40101 SET @saved_cs_client     = @@character_set_client */;
/*!50503 SET character_set_client = utf8mb4 */;
CREATE TABLE `foo` (
  `id` bigint unsigned NOT NULL AUTO_INCREMENT,
  `name` varchar(50) NOT NULL,
  `memo` varchar(255) NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=4 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci;
/*!40101 SET character_set_client = @saved_cs_client */;

--
-- Dumping data for table `foo`
--

LOCK TABLES `foo` WRITE;
/*!40000 ALTER TABLE `foo` DISABLE KEYS */;
INSERT INTO `foo` VALUES (1,'Alice',''),(2,'Bob',''),(3,'Chris','');
/*!40000 ALTER TABLE `foo` ENABLE KEYS */;
UNLOCK TABLES;
/*!40103 SET TIME_ZONE=@OLD_TIME_ZONE */;

まとめ

修正コミットは https://github.com/MariaDB/server/commit/1ba5a0205c です。どうやら、INFORMATION_SCHEMA からカラム情報を取得する際に ORDER BY を明示的に指定する必要があったようで。世界中で使われている超有名ソフトウェアも人間が作っているのだなぁということを、改めて知る良い機会になりました。弘法も筆の誤りとはよく言ったものです。

また、データベースのリストアテストの重要性も改めて認識しました。ペパボでは、定期的にデータベースのリストアテスト²を行っているサービスが基本ですが、今回のような事象のことを考えると、バックアップを取得して安心してしまうのはとても危険であることがわかりますね。当たり前ですが、リストアまで正常に完了することではじめてバックアップとしての意味が成立するわけですので。物理バックアップを採用していたとしても、バックアップファイルの破損可能性が物理バックアップのデメリットとして説明されている以上、リストアテストの重要性は同様だと思います。

ないとは思いますが、もしこの記事を読まれた方の現場で、今回のケースに該当する現場があった場合は、急いでダンプファイルの内容を確認しましょう

とても業務っぽい業務感のある処理や作業の意。 ↩
https://tech.pepabo.com/2023/06/09/db-restore-test/ ↩