はじめに
この記事は、本番環境などでやらかしちゃった人 Advent Calendar 2025 の14日目です。
ここで書くできごとは、私がかなり前に招いたバッチ処理を意図せず遅くしてしまった話です。 今でも覚えていて、思い出すと「あああああああああ! 何を考えているんだこの馬鹿は」と叫びつつ、みかん🍊を探し壁にぶつけたくなる衝動にかられます。
こういうことに気を付けねばならない、こういうことをしてはいけないと自戒の碑として、書いておく次第です（ご迷惑をおかけした関係者の皆様、この件も本当にすみませんでした）。皆様の参考になれば幸いです。
参考）昨年のやらかしエントリ
どのような「やらかし」が起きたか
あるお客様の環境で動くバッチ処理がありました。DBからいくつかのテーブルを元にデータを作り、とある更新系のAPIを叩くという、どこにでもあるようなバッチ処理です。ポイントは
- データ量が多い、実行するとそこそこ時間がかかる。
- とある更新系のAPIは隣のサーバーで動いててDBがインメモリで応答すこぶる速い
- 更新系のAPIを叩くので、単純に二度実行してはいけない。（とある更新系のAPIに冪等性はない）
です。そこで、不用意によかれと思って1文字追加したら、バッチ処理を5倍遅くなり、バッチ処理の終了時間をつきぬけ、各所にご迷惑をおかけした、というものです。
モードという言葉に惹かれるダメエンジニアのふじた🐱
この Java5 のAPIドキュメントを見てください。なじみ深い RandomAccessFile です。（当時Java5で書いてた）
モードという引数があります。
| 値 | 意味 |
|---|---|
| r | 読み込み用に開く。開いたオブジェクトの任意の write メソッドを呼び出すと、IOException がスローされる |
| rw | 読み込みおよび書き込み用に開く。ファイルが存在しない場合は、作成しようとする |
| rws | "rw" と同様に、読み込みおよび書き込み用に開く。ファイルの内容またはメタデータを更新したときは、元になる記憶装置にも同時に適用する必要がある |
| rwd | "rw" と同様に、読み込みおよび書き込み用に開く。ファイルの内容を更新したときは、元になる記憶装置にも同時に適用する必要がある |
モード……何か一つのものに、複数の形がある。うずまきナルトの九尾チャクラモードとか、ジョジョ二部カーズの光のモードとか、 私もオタクの端くれとして「モード」という概念の誘惑に弱いのです。
このバッチ処理における RandomAccessFile の使いどころ
今回とりあげるバッチには、途中でJavaプロセスが落ちたり止まったりしたときの再開用に、この RandomAccessFile を使い"目印ファイル"として、どこまで処理したかが分かる仕組みになっていました。こういうものです。
- バッチ処理の開始時に目印ファイルがあるかどうかチェック。あればRandomAccessFileでファイル末尾にあるIDを読み込む。無ければ新規作成。
- 目印ファイルがないときはデータを処理対象全件ロードしつつAPIを叩く。目印ファイルがあったときは処理が落ちた後の再開時なので、読んだ値であるIDより大きいデータを対象にロードしつつAPIを叩く。どちらも、データはID順に取得する。
- APIを1件叩くのに成功したら、目印ファイルをRandomAccessFileで更新(IDをbyte[]にしたのをファイルに追記)。
- 3.を繰り返す。
- バッチ処理の正常終了時には目印ファイルを削除する。
で、何をしてしまったか
ことは、お客様からこのバッチ処理でAPIを叩く時の変更を依頼され、それをふじた🐱が担当したことから始まります。（この処理は当時の先輩方が作ったものでした。）
必要な箇所を変更し、バッチ処理全体を眺めて、なんだこの RandomAccessFile って？と当時の私は考えました。プログラムとにらめっこすること1時間、目印ファイルの仕組みと意図を理解しました。そこで RandomAccessFile のコンストラクタが
RandomAccessFile mark = new RandomAccessFile( "./mark", "rw" )
となっていることに気づきます。（当時は使ったことがなかった）RandomAccessFile のAPIを見て、そこには上の４つのモードがあることを知り、この説明が目に入りました。
"rws" モードと "rwd" モードの動作は、FileChannel クラスの force(boolean) メソッドに true 引数または false 引数を渡した場合にそれぞれ似ています。ただし、これらのモードはすべての入出力操作に適用されるため、より効率的です。
ふじた🐱「なるほど rws、rwd のモードが効率的らしい。それはいいね、効率は大事、たくさん処理するもの……ファイルの内容を更新したときは、元になる記憶装置……あぁ、ファイルのことか、そっちを更新してほしいから rw から rwd にしよう。テストを実行、よしOK🎵」と
RandomAccessFile mark = new RandomAccessFile( "./mark", "rwd" )
このようについでに変更して、コードをコミットし、お客様環境でリリースしました。
翌朝のモーニングコール
リリースした翌朝5時30分、私の携帯にお客様からの電話が来ました。起きてお客様の電話に応対します。
お客様🧑「ふじたさん、昨日リリースしたバッチ、いつもは4時に始まって4時30分前に終わるのに、今日は5時30分になっても終わらないんですよ。このバッチの後で実行されるバッチがあるから困ってるんだ。何かリリースで変なこと起きてませんか？」
ふじた🐱「えっ、ログファイルの末尾を送ってもらえませんか？」 ※データがたくさんあるのでログファイルが大きい
そうして、来たログファイルには、100件処理をするたびに記録されるバッチの進捗が書いてあります。その進捗がいままでより遅いことに気づきます。データを取得するところで何か起きているのだろうか？と首をひねり、電話でスレッドダンプ(*1)の取得を依頼しました。
(*1) Javaのスレッドダンプは、プロセスが実行中に、ある特定の瞬間の「全スレッドの状態（スタックトレースやロック情報）」をテキスト形式で出力したものです。ハングアップ（応答なし）やデッドロック、パフォーマンス低下の原因を特定するための情報です。
その後6時過ぎに、また電話が鳴って
お客様🧑「スレッドダンプを送りましたよ。あとさっきバッチがようやく終わって、後続の処理が動き始めたよ。今日調べて明日再発しないようにお願い。」
ふじた🐱「承知しました。お手数をおかけします。」
と、問題のバッチ処理が終わったことに一安心し、お客様から来たスレッドダンプを見て、直後にうめきました。
"Main":
at java.io.RandomAccessFile.write (RandomAccessFile.java:xxx)
at HogeBatch.java (HogeBatch.java:yyy)
at ……
RandomAccessFile?!、えっ、もしかしてあの箇所変えてこんなことになったりした？そういえば、テストを100件でしかしていないことを思い出しました。
あわてて、会社に出勤し（当時リモートワークの習慣なんてなかったのです）、10000件でテストをするとたしかに今までより遅い。お客様環境でのデータ量を考えるとアウトな遅さです。いやな予感を覚えつつ、目印ファイルの RandomAccessFile にモードを "rwd" から "rw" に戻すと、いままで同じ速度になります。遅くなった要因はこれだと分かりました。
単純に元に戻すのもまずい
明日を迎える前に対応を終えたいので、RandomAccessFile のモードについて調べ始めます。ようやく rwd が、いわゆるディスクIOのsync（Linuxなら、カーネルキャッシュに格納されたデータをディスクに書き込むこと）を RandomAccessFile#write など書き込み操作のたびに行うこと、これにより1件処理するたびにディスクIOのsyncを発生させ遅くなったことを理解しました。
RandomAccessFile のモードを元の "rw" に戻してよいか、は懸念があります。"rw" だと、もしサーバーが処理中に、サーバーの電源が落ちたとか、OSごと止まったとか起きれば、落ちた瞬間の目印ファイルの内容はメモリだけにありディスクに書かれていません。もしそうなれば、処理再開時、目印ファイルは落ちた瞬間のものではなく少し古いものを取得し、処理済みのものまで再度APIを叩いて二重実行になってしまいます。
いままで、このバッチ処理が稼働してから、動いているサーバーの電源が落ちた、または、OSごと止まったということは幸運にしてなかったので、二重実行が起きる可能性のある問題が顕在化していなかっただけなのです。
対応として、以下のようにすればいいと考えたのですが、どう考えてもテストが明日までに間に合いません。
- 目印ファイルの RandomAccessFile のモード は "rw" に戻す。
- 処理再開したときは、隣のサーバーの更新系のAPIを叩く前に、参照系のAPIを呼ぶ。
- APIで得られた更新時刻を元に、このバッチが更新を呼んだか判別する（※このバッチ処理のみが更新するので）。
- もし更新していれば更新系のAPIを呼ぶことはスキップし次のIDの処理へ（ログに書いておく）。更新していなければ更新系のAPIを呼ぶ（これ以後は2.3.のチェック不要）。
このため
- 処理が遅くなった当日は、「目印ファイルの RandomAccessFile のモード は "rw" に戻す。」修正だけリリース。お客様にもしサーバーが落ちたりしたら、二重実行の可能性があることを報告（お客様は了承してくださった）。
- 後日、「処理再開したときは、隣のサーバーの更新系のAPIを叩く前に、参照系のAPIを呼ぶ～」まで含めた修正その2をリリース
と二段階にわけた対応を行いました。
ちなみに、このバッチ処理は3年ほど前に役目を終えたのですが、"修正その2"に含めた「もし更新していれば更新系のAPIを呼ぶことはスキップし次のIDの処理へ」という幽霊現る、のパターンはログを調査したところ、発生していませんでした。
その「やらかし」を起こさないために次どうすればいか
これはまず
- たとえ、問題がなさそうに見えても 不用意に必要ない箇所を変更しない。 変更するときは充分なテストを実施してから行う。
に尽きます。まじでこれです。RandomAccessFile のモード を "rw" から "rwd" に変えても、処理結果は変わりませんが、その当時の環境ではディスクIOに比較的時間がかかります。結果、この1文字の変更で、いつもは30分未満で終わる処理が2時間と4倍遅くなってしまいました。
加えて
- 理解していないことを理解した気になって物事を進めない
もあります。「理解した気になって」いることに気づくことは難しいのですが、当時の私がこの「効率的」の意味を理解していれば、不用意な変更をしようと思わなかったわけです。
"rws" モードと "rwd" モードの動作は、FileChannel クラスの force(boolean) メソッドに true 引数または false 引数を渡した場合にそれぞれ似ています。ただし、これらのモードはすべての入出力操作に適用されるため、より 効率的 です。
この「効率的」だけ見ると、"rws" モードと "rwd" モードの方が速いんじゃないか？と魅惑的に読めてしまうのです。たいがいは APIリファレンス の rws,rwd に書かれた「元になる記憶装置にも同時に適用する必要がある」を、ディスクIOのsync操作と気づいて引き返しますが、引き返さず「効率的なんでしょ」と、そのまま突き進んでしまったのです。
この「効率的」は、
- RandomAccessFileでディスクに書いた内容を、sync でディスクに強制的に書き込みを促すときに
- "rw" で RandomAccessFile を開いて、write するたびに FileChannel#force を経由して書き込むよりは
- "rws"や"rwd"の方が、JavaとOSがよしなにしれくれるから効率的
APIリファレンスは、このようにsyncするのを効率が悪いと言っている
RandomAccessFile raf = new RandomAccessFile( "./foo", "rw" )
raf.write(data); //データが大きかったら途中でforceしなくていいのか？
raf.getChannel().force(false); //毎回書くのうざったくないか？書き忘れないか？
なので、はなからこう書いた方が効率的、と（APIリファレンスは言っている）
RandomAccessFile raf = new RandomAccessFile( "./bar", "rwd" )
raf.write(data); //書き忘れることないしデータが大きいときのsyncはJavaやOSに任せられる
という意味で、rw に比べてなにか入出力操作が効率的と説明しているわけではありません。
おわりに
ご高覧ありがとうございました。何かお気づきの点がございましたらご指摘いただけると幸いです。
ディスクがSSDになった昨今、おそらく「1文字変えてバッチ処理が4倍遅くなる」ということはないと思うのですが、不用意な変更が惨事を招くことは、コンピューターの性能があがっても起きることと思いますが、みなさまの「他山の石」になれば、と書いてみました。