防壁すべてに穴が空いていた

この記事は、AEON Advent Calendar 2024の13日目です🎉

こんにちは。イオンスマートテクノロジー株式会社のCTO室テックリードチームに所属しております、うしおです。
気づけばもう年末でした。子供が生まれてから時の速さが3倍になった気がします。

今回は、関わったプロダクトの不具合と、そこに至るまでの数々の地雷のお話をします。

背景

２つのシステム間でデータを連携するバッチがありました。
日次でいくつかのDBテーブルの内容を他システムへコピーしています。

• 単純化のために、データ例を書籍としました。本のタイトルとISBNコードを持ちます。
• ISBN（国際標準図書番号：International Standard Book Number）は書籍ごとにユニークです。

不具合

ある日、プロダクトBの利用者から連絡が来ました。

🤓「んん？APIでエラーが出てるのかな？」
🤓「レスポンスは200が返ってきてるけどデータが0件だな。DBも見るか」
😨「え・・・テーブルにもレコードが無いやん」
😌「直近のリリースは・・・関係してないかな」
😨「あ・・・深夜のデータ連携バッチがエラー吐いてる」

調査

こんなことしてました。

①ファイルを作成し、先頭に以下を書き込む。

set autocommit=0;
delete books;

②mysqldumpを実行し、上記ファイルの続きに以下の内容を書き込む。

-- MySQL dump 10.13  Distrib 5.7.39, for Linux (x86_64)
--
-- Host: localhost    Database: hoge
-- ------------------------------------------------------
-- Server version	5.7.39

/*!40101 SET @OLD_CHARACTER_SET_CLIENT=@@CHARACTER_SET_CLIENT */;
/*!40101 SET @OLD_CHARACTER_SET_RESULTS=@@CHARACTER_SET_RESULTS */;
/*!40101 SET @OLD_COLLATION_CONNECTION=@@COLLATION_CONNECTION */;
/*!40101 SET NAMES utf8 */;
/*!40103 SET @OLD_TIME_ZONE=@@TIME_ZONE */;
/*!40103 SET TIME_ZONE='+00:00' */;
/*!40014 SET @OLD_UNIQUE_CHECKS=@@UNIQUE_CHECKS, UNIQUE_CHECKS=0 */;
/*!40014 SET @OLD_FOREIGN_KEY_CHECKS=@@FOREIGN_KEY_CHECKS, FOREIGN_KEY_CHECKS=0 */;
/*!40101 SET @OLD_SQL_MODE=@@SQL_MODE, SQL_MODE='NO_AUTO_VALUE_ON_ZERO' */;
/*!40111 SET @OLD_SQL_NOTES=@@SQL_NOTES, SQL_NOTES=0 */;

--
-- Dumping data for table `books`
--

/*!40000 ALTER TABLE `books` DISABLE KEYS */;
INSERT INTO `books` VALUES (1,'パンどろぼうとりんごかめん','9784041153024');
INSERT INTO `books` VALUES (2,'そういうゲーム','9784041155288');
INSERT INTO `books` VALUES (3,'ノームの世界一のんきなくらし','9784065379387');
/*!40000 ALTER TABLE `books` ENABLE KEYS */;

/*!40103 SET TIME_ZONE=@OLD_TIME_ZONE */;

/*!40101 SET SQL_MODE=@OLD_SQL_MODE */;
/*!40014 SET FOREIGN_KEY_CHECKS=@OLD_FOREIGN_KEY_CHECKS */;
/*!40014 SET UNIQUE_CHECKS=@OLD_UNIQUE_CHECKS */;
/*!40101 SET CHARACTER_SET_CLIENT=@OLD_CHARACTER_SET_CLIENT */;
/*!40101 SET CHARACTER_SET_RESULTS=@OLD_CHARACTER_SET_RESULTS */;
/*!40101 SET COLLATION_CONNECTION=@OLD_COLLATION_CONNECTION */;
/*!40111 SET SQL_NOTES=@OLD_SQL_NOTES */;

-- Dump completed on 2024-xx-xx xx:xx:xx

③ファイルの末尾に以下を追加する。

commit;

④GCPのクラウドストレージへ作ったファイルを配置する。
⑤gcloud sql import sqlを使い、SQLを実行する。

結果を見る限り、deleteだけちゃんと動いてinsertに失敗、ロールバックもされていないようだ。
一応、トランザクションを張ろうという意思だけは感じるが・・・。

原因

すでにお気づきの方も多いかと思いますが、

/*!40000 ALTER TABLE `books` DISABLE KEYS */;

があるせいですね。
トランザクション中でALTERを実行すると暗黙的なコミットが発生します。

• deleteだけコミット
• autocommit=0により再度トランザクションが自動で開始
• insertでエラーが発生し、ロールバック

見事にデータを全破壊しました。

さらに・・・

発生したSQLエラーは、isbnカラムのUnique制約違反でした。

🤔「プロダクトAのデータにISBNが重複したものがあるってこと？」
🤓「は？プロダクトAとプロダクトBのisbnカラムはUKやろ？」
　↓
😡「プロダクトAのisbnにUK付け忘れとるやんけ」

いやいや・・・

🤔「だって入力時にバリデーションもしてるやろ？」
🤓「画面で試してみると、ちゃんと重複エラー出るな」
　↓
😡「CSV取り込みの方のバリデーションがバグってて重複データ入るやんけ」

おわりに

ようするに異常系テストなにもやってないのに稼働してた・・・。

絶賛採用中です！

イオンスマートテクノロジーではエンジニアをはじめとした様々な職種を積極的に採用中です！
これからとてもおもしろいフェーズへ突入していくと思いますので興味のある方は是非カジュアル面談などで話を聞いてください！