エラーメールは来ませんでした。ジョブが1件も動いていなかったからです

朝、夜間処理のエラーメールが1件も届いていない。いつもなら「昨夜の処理は問題なかった」と判断する場面です。

ところが実際に起きていたのは、「失敗したジョブがなかった」のではなく、対象のジョブが1件も実行されていないという状態でした。処理が途中で失敗したのではありません。処理を開始するところまで到達していなかったので、異常終了そのものが発生していませんでした。

「ジョブが異常終了したらメールを送る」という既存の監視では、これを何も検知できません。エラー通知がないことと、予定された処理が正常に動いたことは、同じではありませんでした。

製品名や具体的なジョブ名は伏せますが、夜間バッチを運用している環境なら、業種を問わず同じ見落としが起こり得ます。この事象をきっかけに分かった「失敗だけを監視することの穴」と、原因をどこまで切り分けられたのか、そして特別な監視製品をすぐ追加しなくても始められる確認方法を整理しておきます。

エラーメールは0件。それでも必要なデータができていなかった

対象になったのは、決められた時刻になると複数の処理を自動で起動する、ごく一般的なジョブ管理の仕組みです。夜間に処理が正常終了すれば、その結果を翌日の業務で使います。処理中にエラーが出た場合は通知メールが届く運用でした。

だから日常的には、「エラーメールが届いていないこと」が、暗黙のうちに正常の判断材料になっていました。

この前提が崩れたのが今回です。異常に気付いたきっかけは監視ではなく、利用部門からの問い合わせでした。翌日の業務で使うはずのデータが上がっていない、という連絡が入って初めて確認を始めています。

まず処理結果を見ると、必要なデータができていません。そこでジョブの実行履歴を開きました。

通常の障害なら、実行日時とともに「異常終了」などの履歴が残っているはずです。ところが今回は、エラーで終了したジョブが並んでいるのではなく、その日の実行履歴自体がありませんでした。対象は夜間に動く2本のジョブで、どちらも当日の行が存在しません。

一部のジョブだけが失敗したのではなく、対象となる処理がそもそも起動していなかったわけです。

ここでエラーメールが来なかった理由もつながりました。ジョブが起動した後で失敗すれば、異常終了として通知できます。しかし、ジョブを起動するところまで進んでいなければ、ジョブ自身は失敗することすらできません。

「通知されなかった障害」ではなく、通知の対象となる処理そのものが始まっていなかった。これが今回のポイントでした。

「異常終了」と「未実行」は監視上まったく別だった

今回の件で見直したのは、「失敗を監視しているから大丈夫」という考え方です。ジョブ管理では正常終了と異常終了に目が向きますが、その手前に「予定された処理が本当に起動したか」という状態があります。

夜間ジョブには3つの状態がある

① ジョブが起動して正常終了 → 正常

② ジョブが起動して異常終了 → エラー通知で検知できる

③ ジョブそのものが起動しない → 異常終了が発生しないため、失敗通知だけでは検知できない

これまで確認できていたのは、②の「異常終了が発生したかどうか」でした。今回問題になったのは③です。

エラーメールが届いていないという事実から分かるのは、「通知対象となる異常終了を確認していない」ということだけ。「今日のジョブが予定どおり実行された」ことまでは確認できていません。この2つは似ているようで大きく違います。失敗通知は、処理が開始された後に異常が起きたことを教えてくれます。処理そのものが開始されなければ、通知を出す機会すらありません。監視対象のジョブは、ただ沈黙したままです。

この違いに気付くと、監視の考え方も変わりました。

ファイル連携なら、「転送処理がエラーになったか」だけでなく、「予定時刻までに今日のファイルが到着したか」を見ます。バックアップなら、「バックアップ処理が失敗したか」だけでなく、「今日の日付のバックアップが実際に作られているか」を見ます。

エラーが発生したことを検知する監視と、期待した処理が実行されたことを確認する監視は別物でした。

監視を考えるときは「何が起きたら知らせるか」だけではなく、予定されたことが何も起きなかった場合をどう見つけるかまで設計しないと、同じ穴が残ります。無音を正常と読む監視になっていないか、という視点です。

逆に、異常終了として検知できたケースもあります。JP1/FTPの夜間伝送が421エラーで止まった件では、エラーは通知されたものの、同じメッセージで原因が2回とも違いました。検知できることと原因が分かることは別です。

ジョブではなく、ジョブを起動する側のサービスが止まっていた

複数のジョブに実行履歴がないことから、次に確認したのがジョブを起動する側です。

夜間処理では、個々のジョブとは別に、予定時刻を確認してジョブを起動するバックグラウンドのサービスが動いています。今回はこちらのサービスが停止していて、その結果として後続のジョブが開始されていませんでした。

個々のジョブだけを見ていると、「なぜ複数の処理が一斉に動かなかったのか」が分かりません。共通している起動元まで一段戻ると、複数ジョブがそろって未実行になった理由を説明できます。切り分けの順序として、覚えておく価値のある視点でした。

停止の直接の原因も確認できました。Javaのプログラムが利用するメモリ領域であるJVMのヒープが枯渇し、その結果としてサービスが停止していました。ヒープが尽きる、サービスが停止する、後続のジョブが起動しない、という流れです。

ここまでは切り分けられています。残っているのは、「なぜヒープが枯渇したのか」です。

「ではヒープを増やせばいい」とすぐに言えない理由

原因がヒープ不足だと分かると、次に考えたくなるのは「割り当てを増やせば解決するのでは」という対応です。ただ、設定変更を決める前に、ヒープがどう増えているかを見ておきます。

ヒープ使用量の推移を見ると、夜間ジョブのうち特定の1本が動いている時間帯だけ、使用量が右肩上がりに伸びていました。他の時間帯では同じ伸び方をしていません。

少なくとも今回のヒープ枯渇は、すべてのジョブが均等にメモリを使った結果というより、特定の1本の処理と強く関係していると考えています。

ヒープ使用量のグラフとジョブのスケジュールを時刻で突き合わせるだけでも、「どの処理を調べるべきか」はかなり絞れます。今回も、そこから対象ジョブを1本まで絞り込みました。

次に見たいのは、そのジョブが終了した後にメモリ使用量がどう変化するかです。

  • 処理後に使用量が大きく下がる場合:特定ジョブの実行中に一時的なメモリ使用量が大きくなり、現在の最大ヒープでは不足している可能性が高まります。
  • 処理後も高い水準が続く場合:不要になったオブジェクトが残っている可能性だけでなく、キャッシュの保持やGCの動作なども含め、追加の切り分けが必要になります。

ただし今回は、この判定まで進めていません。処理完了後の状態を十分に観測する前に、ヒープが上限へ達してサービスが停止してしまうためです。

現在地を整理すると、こうなります。ヒープ枯渇によってサービスが停止したことは確認できました。ヒープ使用量が増える時間帯から、関係するジョブも1本まで絞り込めています。一方で、最大ヒープを増やせば解決するのか、ジョブ側のメモリ使用について追加対応が要るのかは、まだ判断できていません。

数字も書いておきます。現在の最大ヒープは1GBで、今回の事象を受けて4GB程度への拡張を選択肢として検討中です。ただし、「1GBだから少ない」「4GBへ増やせば解決する」と判断したわけではありません。今わかっているのは、現在の設定では特定ジョブの実行時間帯にヒープが上限へ達している、というところまでです。

ここから先へ進む方法としては、GCログなどを取得してメモリ回収の状況を確認する方法や、一時的に最大ヒープを広げて対象ジョブを完走させ、処理後の使用状況を観測する方法を考えています。

なお、GCログの設定方法や最大ヒープ変更後の再起動要否は、使用しているJavaや製品、サービスの構成によって異なります。本番環境で試す場合は、事前に設定変更の影響や停止の要否を確認する必要があります。現時点では、これらを恒久対応として実施したところまでは進んでいません。

そして、この記事の本題との関係ではここが肝心です。原因の切り分けが途中でも、監視と復旧は先に手を打てます。このサービスが停止すると個々のジョブは異常終了せず、失敗通知も来ない。この現象が分かっているだけでも、次に同じことが起きたときの初動は大きく変わります。

夜間処理が止まる原因は、起動側だけとは限りません。SAP向け9桁コードの読替マスタに登録漏れがあった件では、ジョブは動いていたものの、データ側の不備で連携が止まりました。

費用をかけずに「今日も動いた」を確認する方法

今回のような未実行を見つけるのに、最初から新しい監視製品を入れなくてもかまいません。まずは現在の運用で、「失敗したこと」だけでなく「正常に動いたこと」を確認できるかを考えます。

  • 正常終了の通知を確認する:利用しているジョブ管理製品に成功時の通知機能がある場合は、異常終了だけでなく正常終了も確認対象にします。毎日来るはずの通知が来なければ、「今日は何か違う」と確認を始めるきっかけになります。設定変更だけで対応できる製品であれば、比較的着手しやすい方法です。
  • 処理結果そのものを確認する:更新されるはずのテーブル件数、生成ファイルの日付、最終更新時刻などを翌朝確認します。追加費用はほぼありませんが、人による確認を続ける場合は運用負荷が残る点が、成功通知との違いです。
  • 予定時刻までに完了しなければ確認する:通常は毎朝6時までに終わる処理であれば、6時を過ぎても当日の完了結果がない状態を異常として扱います。「失敗したか」ではなく「期限までに終わったか」を見る方法です。
  • ジョブを起動するサービスも監視する:既存の監視環境がある場合は、個別ジョブだけでなく起動役のサービスも確認対象にします。サービス停止を早く検知できれば、複数のジョブが未実行になる前に気付ける可能性があります。

始めやすいのは、正常終了通知と処理結果の確認です。これまで「エラーメールが来ていないか」を見ていたところに、「昨日まで毎日来ていた成功通知が今日も届いたか」「今日の日付のファイルがあるか」を足すだけでも、未実行を疑う材料が増えます。

ただし、「成功通知を設定すれば必ず未実行を検知できる」わけではありません。通知メール自体の送信障害など、別の要因もあり得ます。成功通知は、届くはずのものが届かないことを異常のサインとして使える、という位置付けです。

使える機能はジョブ管理製品によって違うので、まず今使っている仕組みに何を設定できるか確認するところからになります。

切り分けが途中でも、復旧手順は先に作れる

恒久対応の方針が固まっていない段階でも、同じ現象が起きるたびに一から調査しなくて済みます。一度復旧できたのなら、そのとき何を確認したのかを手順として残せます。

今回の流れなら、まずジョブの実行履歴を確認します。次に、ジョブを起動する側のサービスが稼働しているかを確認します。サービスを復旧した後、どのジョブが未実行なのかを特定し、必要な処理を再実行する。この順番です。

今回は未実行だった2本のジョブを再実行し、どちらも正常終了することを確認しました。

この実績が一度あれば、次回からは「サービスが停止していた場合、どこを確認し、何を再実行すればよいか」という復旧手順に落とせます。実際に使う管理画面や確認項目まで書いて1枚程度にまとめておけば、担当者本人が不在でも初動を取れます。

ただし、再実行には注意が必要です。

サービスが停止する直前までに一部のジョブだけ正常終了していた場合、関連する処理をすべて最初から流すと、同じデータを2回登録したり、外部システムへ二重送信したりする可能性があります。

だから、「どのジョブまで終わっていたか」「対象ジョブだけを再実行できるか」「同じ処理を2回実行しても問題がないか」は、障害が起きていないときに確認しておくほうが安全です。

恒久対策の判断には時間がかかることがあります。それが決まるまで復旧手順を作れないわけではありません。再発そのものをゼロにできなくても、発見から復旧までの時間を短くする対策は先に進められます。

監視の必要性は「気付くまでの時間」で考える

監視を追加したいと相談すると、「そこまで必要なのか」「費用をかけるほどなのか」という話になります。「監視を強化したい」という言葉だけでは、効果が伝わりにくいからです。

今回のようなケースでは、機能の話よりも、障害に気付くまでの時間で説明すると通りやすくなります。

「夜中にジョブが動かなかったとき、翌朝に利用部門から『データがありません』と言われて初めて気付く状態」と、「本来の完了時刻を過ぎた段階で確認を始められる状態」では、その後の復旧開始時刻が変わります。

夜間処理への気付きが遅れれば、その分だけ再実行も遅れ、後続業務の開始にも響きます。監視の目的は、アラートを増やすことではなく、異常発生から発見までの時間を短くすることでした。

最初から予算が要る対策だけを考えなくてもかまいません。現在の製品で正常終了通知を設定できないか確認する。朝のチェックへ処理結果を一つ追加する。復旧手順を文書化する。ここから始めて、それでも見逃しが残るなら、期限監視やサービスの死活監視を検討します。

原因の切り分けが途中であることも、監視を見直さない理由にはなりません。ヒープ枯渇までは分かった。関係するジョブも絞れた。ただし恒久対策を決めるには追加確認が要る。その状態でも、再発時の発見と復旧を早めることはできます。

もし今、「エラーメールが来ていないから大丈夫」と判断しているなら、まず正常終了を確認する方法がないか見てみてください。「成功したら通知」を追加できれば、少なくとも「いつも届く通知が今日は来ていない」という、未実行を疑うきっかけを一つ増やせます。

コメント

タイトルとURLをコピーしました