はじめに

処理実行で「処理結果IDが取得できない」と表示されたとき、原因が後段APIにあるとは限りません。

実際には、処理実行の前段で呼ばれる外部サービス、WireMockのスタブ選択、レスポンスXML、JAXBによる変換、再起動時の設定反映など、複数の要因が連鎖して失敗することがあります。

この記事では、WireMockを利用する外部連携試験で発生した複合障害を題材に、どのように原因を切り分けたかを整理します。特定の製品や識別子には依存しないよう一般化し、同種の調査で使える確認順序としてまとめます。

最初に見えていた事象

画面では、処理結果IDを取得できない旨のエラーだけが表示されていました。BFFの応答は次の状態です。

resultCd = 6
reportAcceptNumber = null
PDF総ページ数 = null

構成は次のとおりです。

UI
 ↓
BFF
 ↓
BL
 ↓
外部サービス群
 ↓
後段処理API

この時点で分かるのは、BFFとBLの通信は成立していることと、BL配下のどこかで失敗していることだけです。画面のエラー文だけから後段APIを調べ始めると、遠回りになりやすい状態でした。

調査は実際の処理経路を確認するところから始める

最初に確認したのは、外部サービスのモックであるWireMockにリクエストが届いているかどうかです。

WireMockのrequest journalを見ると、対象のリクエストは到達しており、HTTPステータスも200でした。しかし、対象ケース専用のmappingではなく、全件向けのフォールバックmappingに一致していました。

対象リクエスト
 ↓
汎用mappingに一致
 ↓
別ケース用のレスポンスを返却
 ↓
HTTP 200

ここで重要なのは、HTTP 200が期待どおりの処理を意味しない点です。WireMockではリクエストを受け付け、何らかのmappingに一致すれば200を返せます。期待したスタブが選択されたかは、別途確認する必要があります。

以降はHTTPステータスだけでなく、次の項目を確認対象にしました。

request journal
matched stub ID
requestのXPath条件
priority
bodyFileName
レスポンス内の識別子

ローカルの資材と稼働中のWireMockは別物

ローカルには、対象ケース専用のmapping JSONが存在していました。対象条件で絞り込むXPath、優先度、専用のbodyFileNameを持つ資材です。

一方で、WireMock Admin APIのGET /__admin/mappingsを確認すると、そのmappingは稼働中のWireMockに存在していませんでした。

ローカルにmappingファイルがある
≠
稼働中のWireMockがmappingを読み込んでいる

原因の切り分けとして、Admin APIから専用mappingを一時登録しました。すると対象リクエストは専用mappingに一致し、期待するレスポンスが返るようになりました。

この結果から、WireMock自体の障害ではなく、正しい資材が稼働状態へ反映されていない問題だと分かります。

ただし、主対象に対する応答を直しても処理実行は成功しませんでした。

画面上の1処理が複数の外部照会を含んでいた

BLログをtransaction IDで追跡すると、処理実行は主対象への照会だけで完結していないことが分かりました。

主対象が正常でも、関連対象の照会が失敗すれば、処理全体は失敗します。画面上は1回の操作でも、裏では複数の外部呼び出しが実行されている前提で調査する必要があります。

このケースでは、関連対象のmapping自体は存在していましたが、mappingが参照するXMLファイルが__filesにありませんでした。

mappingに一致
 ↓
bodyFileNameのXMLを読み込む
 ↓
ファイルが存在しない
 ↓
FileNotFoundException
 ↓
WireMockがエラー応答
 ↓
BLが異常終了

この時点で、後段APIの前段で失敗していると明確に切り分けられました。

XMLを追加すると、次の障害が見えた

関連対象用のXMLを追加すると、FileNotFoundExceptionは解消しました。しかし次はBL内部でSProductInquiryDto = nullとなり、NullPointerExceptionが発生しました。

ここで調査対象は、ファイルの有無から「XMLレスポンスをBLがDTOへ変換できているか」に移ります。

XMLは構文として正しくても、SOAPクライアントやJAXBが期待する形式とは限りません。今回のBLはWSDLから生成したJAXBクラスを利用していました。

BLは、次のようにoutPayload自体が特定の名前空間に属するXMLを期待していました。

<ns2:outPayload xmlns:ns2="...SM_PRA03">

一方、モックXMLは次の状態でした。

<outPayload xmlns:ns2="...SM_PRA03">

後者もXMLとしては正しい形式です。しかしoutPayload自身は名前空間なしとして扱われます。JAXBが期待するQNameと一致せず、期待どおりにDTOを生成できません。

XMLの構文が正しい
≠
JAXBが期待どおりにアンマーシャルできる

主対象と関連対象のXMLでルート要素の名前空間を修正し、WSDL由来の定義と合わせました。

未定義要素は正常に見えるレスポンスを壊す

名前空間を直した後も、NPEは残りました。そこで、正常に動いている既存ケースのXMLと対象ケースのXMLを比較しました。

比較の結果、対象XMLにはBL側のJAXBスキーマに定義されていないapplicationTmstmp要素が含まれていました。

未定義要素を含むレスポンス
 ↓
アンマーシャルが期待どおりに完了しない
 ↓
outParamを取得できない
 ↓
DTOがnullになる
 ↓
後続処理でNullPointerException

不要な要素を削除し、名前空間、要素構成、データの役割を既存の正常ケースと合わせました。

ここでのポイントは、NPEが出た行にnullチェックを追加することではありません。DTOがどこでnullになったかを、レスポンス変換まで上流へ追うことです。

データの役割もモックに反映する

XMLに必要な値が含まれていればよいわけではありません。どの対象の応答に、どの情報が含まれるべきかも実際の処理構造に合わせる必要があります。

今回のケースでは、次のような役割分担が正しい状態でした。

主対象: 属性情報を複数件返す
関連対象: 補助情報を1件返す

当初は主対象のレスポンスに補助情報を含めるなど、実際の構造と異なるモックになっていました。単体のXMLとして値が入っていても、BLの処理順や後続判定と整合しなければ、処理実行のためのデータにはなりません。

priorityとbodyFileNameはセットで確認する

XMLを修正した後、再び主対象の要求が汎用mappingに一致する事象が発生しました。ローカルの正式資材にはpriority = 1が設定されていましたが、稼働中のmappingには反映されていませんでした。

専用mappingと汎用mappingの条件が重なる場合、priorityが欠けるだけで意図しないレスポンスを返します。

また、専用mappingに一致していても、bodyFileNameが古い共通ファイルを指していれば正しいXMLは返りません。参照先のファイルがなければ、WireMockは実行時にエラーになります。

mappingを確認するときは、次を一組として見る必要があります。

matched stub
XPath
priority
bodyFileName
__filesにある実ファイル

JSONファイルの内容だけで判断せず、実行時にどのmappingとファイルが使われたかを確認することが大切です。

Admin APIの修正と永続ファイルの修正を分ける

Admin APIでmappingを直接直すと、処理実行は一時的に正常になりました。しかし、JenkinsからWireMockを再起動すると元の状態へ戻りました。

調べると、このJenkinsジョブはローカル資材をサーバーへ転送するものではなく、サーバー上にあるmappingsと__filesをWireMockへ再読込する処理でした。

Admin APIで一時修正
 ↓
メモリ上では正常
 ↓
WireMockを再起動
 ↓
サーバー上の古い永続ファイルを再読込
 ↓
修正前の状態に戻る

恒久対応では、mapping JSONとレスポンスXMLをともにサーバー上の永続配置先へ反映する必要があります。そのうえで再起動後に、Admin APIと実リクエストで再確認します。

再起動成功は即時の正常性を保証しない

JenkinsがSUCCESSになった直後は、mapping一覧に反映されていなかったり、実リクエストが失敗したりすることがありました。数分後には正常になったため、WireMockの再起動、資材の読込、待受開始に時間差がある可能性を考慮しました。

原因を断定できない場合でも、運用上はJenkinsの成功表示を正常判定に使わない方が安全です。再起動後は少し待ち、次を確認してから試験を実施します。

Admin APIで対象mappingが存在する
XPath、priority、bodyFileNameが期待どおりである
実リクエストが200を返す
request journalで専用mappingへの一致を確認する
レスポンス内容が期待どおりである

また、mapping JSONに固定UUIDを設定していない場合、再起動や再登録でUUIDが変わることがあります。以前のUUIDを前提に個別取得すると404になっても、mappingが消えたとは限りません。再起動後は一覧から、XPath、priority、bodyFileNameを使って現在のmappingを探し直します。

正常系との比較で分岐点を見つける

最終的な切り分けで有効だったのは、同じ処理を正常に実行できる別ケースのログとの比較です。

正常系では、外部照会の後に処理データ生成、後段処理APIの呼び出し、処理結果IDの取得まで進んでいました。一方、異常系は外部照会の途中で止まっていました。

この比較により、後段APIやテンプレートを調べる前に、外部照会とモック応答を直すべきだと判断できます。

異常ログだけを追うと、例外が多く、どこから着手すべきか判断しづらくなります。正常系のログと並べ、最後に共通している処理と最初に分岐した処理を確認すると、原因範囲を狭めやすくなります。

今回のデバッグ遷移

今回の調査は、次のように進みました。

原因は1つではありませんでした。1つ修正するたびに、次の障害が見える複合障害でした。

同じ問題を早く切り分ける手順

次回同種の障害が起きた場合は、次の順番で確認すると効率よく進められます。

画面エラーの発生時刻を記録する
BFFのresultCdと応答項目を確認する
transaction IDを取得する
BLログで最初の例外と最後に成功した外部呼び出しを確認する
WireMockのrequest journalで実際に一致したstubを確認する
XPath、priority、bodyFileName、__files上の実ファイルを確認する
主処理以外の追加照会がないか、BLログから確認する
XMLの名前空間、QName、未定義要素をWSDLとJAXB定義に照らして確認する
正常ケースのログとXMLを比較し、最初の分岐点を特定する
Admin APIの一時状態とサーバー上の永続ファイルを分けて確認する
再起動後は待機してからAdmin APIと実リクエストを再確認する
最後は画面だけでなく、request journal、実レスポンス、BLの正常経路まで確認する

まとめ

処理実行の失敗では、画面のエラー内容やHTTP 200だけで原因を判断できません。

今回、単独では正常に見えた次の状態はいずれも、正常性の証明になりませんでした。

HTTP 200が返っている
XMLの構文が正しい
mappingファイルがローカルに存在する
JenkinsジョブがSUCCESSになっている

信頼できるのは、実リクエストがどのstubに一致し、どのレスポンスを返し、BLがどこまで正常に進んだかという実行結果です。

複合障害では、NPEが起きた場所だけを見るのではなく、その値がnullになった上流まで遡ることが重要です。モック、XML契約、データ構造、デプロイ後の稼働状態を順に確認すると、原因が重なった障害でも着実に切り分けられます。