システム移行時のログメッセージ引き継ぎで経験したこと
IT技術
はじめに
長く使っているシステムを運用しつつ、引き継ぎながら新しいシステムにリニューアルしていく、ってことはそこそこあるかと思います。
その時には、運用を出来るだけ止めないとか、旧システムよりも使いやすくしたいとか、など色々と対応すべきことはありますが、今回は旧システムから新システムへのログ出力の引き継ぎでいろいろと起きたことや感じたことを書いていきます。
背景
旧システムをリニューアルするにあたって、出力されていたログメッセージや表示項目も整理して変わることになりました。
それでいて、旧システムの運用チームで今まで対応してきたエラー対応は資料として残っているので、そのまま継続して資料が利用できるようにしてリニューアル後もスムーズにエラー対応したい、なので旧エラーメッセージと新エラーメッセージは紐付けておきたい、といったのが今回の背景となります。
REST-API から gRPCのAPIへ
APIの処理は、旧システムではREST-APIを採用していましたが、リニューアル後はgRPCでのAPI対応となりました。
これによってエラーコードも扱い方が変わってきます。
例えばREST-APIでは、問い合わせた結果が無くてエラー出力する時にHTTPレスポンスのステータスコード「404:NotFound」をレスポンスしていたとします。
gRPCで同じようなことをしたい場合、メソッドの呼び出し自体が成功していると、そのメソッド内でエラーが起きようともHTTPレスポンスのステータスコードは「200:OK」でレスポンスされるため、独自で持っているコードで返却する必要があります。今回の場合だと、「5:NotFound」がそれに該当するかと思います。
その他のステータスに関しては基本的に以下のような対比になります。
コード | 名称 | 大まかな概要 | RESTでのステータスコード |
0 | OK | 正常系 | 200:OK |
1 | Cancelled | 呼び出し元の処理キャンセル | 499:Client Closed Request |
2 | UnKnown | 不明なエラー | 500:Internal Server Error |
3 | InvalidArgument | 不正な引数指定 | 400:Bad Request |
4 | DeadlineExceeded | タイムアウト | 504:Gateway Timeout |
5 | NotFound | 見つからない | 404:Not Found |
6 | AlreadyExists | すでに存在する | 409:Conflict |
7 | PermissionDenied | 操作権限無し | 403:Forbidden |
8 | ResourceExhausted | リソース不足 | 429:Too Many Requests |
9 | FailedPrecondition | 実行拒否 | 400:Bad Request |
10 | Aborted | 操作中止 | 409:Conflict |
11 | OutOfRange | 操作範囲超え | 400:Bad Request |
12 | Unimplemented | サポートされていない操作 | 501:Not Implemented |
13 | Internal | 内部エラー | 500:Internal Server Error |
14 | Unavailable | 利用不可 | 503:Service Unavailable |
15 | DataLoss | データ欠損 | 500:Internal Server Error |
16 | Unauthenticated | 認証情報無し | 401:Unauthorized |
参考:https://grpc.io/docs/guides/error/#error-status-codes
考え方として
まずやることとしては、新旧それぞれのシステムのエラーコードの紐付けをするところからかなと思います。
REST-APIで「404:NotFound」で返していたものは、gRPCでは「5:NotFound」で返すように設計するのが良い感じになります。
ただ、処理によってはNotFoundだけど「400:Bad Request」で返す、とか業務内容に合わせてエラーコードを調整していたものもあるかと思います。そこは内容を確認して適宜調整が必要かなと思われます。
このエラーコードの紐付けとメッセージの紐付けが出来れば、新しい方のシステムでも同じようにエラー時の対応が運用側でも出来そうかなと思います。
1<旧システムのレスポンス例>
2{
3 code:404
4 message:idが見つかりません。検索し直してください。
5}
1<新システムのレスポンス例>
2{
3 status:200
4 code:5
5 message:idが見つかりませんでした。
6}
ここまでは方針として記載しましたが、実際にはそう簡単にはいかず。。。
以降は実際に対応した時の作業をざっくりと記載します。
運用チーム対応情報から整理していく
実際のメッセージの紐付け対応は、新システムの実装がだいたい済んでテストフェーズに入った頃に始まりました。
このタイミングで運用側と確認し始めて、必要なものを揃える流れとなりました。
まず旧システムのエラーメッセージに対する運用の対応についてざっくりと説明します。
旧システムはエラー対応として、運用チームがログに出力されたエラーメッセージをもとに不具合の確認をし、状況に応じてバグかどうかを開発チームに問い合わせて解決する、といった流れで動いてます。
例えば、ログイン後に目次画面から自分のユーザ情報を確認する画面を見ようとします。
この時に、
1{
2 code:401
3 message:ユーザ情報が確認出来ませんでした。ログインしてください。
4}
といったエラーメッセージが出たとします。
この場合、おおまかに以下の状況がまず考えられます。
- 利用者がログイン中のページを長時間放置し、セッションが切れたあとに処理ボタンを押した。
- 利用者がログインせずに処理ボタンを押した。
- 利用者が正常にログインしているのに表示された。
運用チームは利用者にどういう状況だったか確認します。
1の長時間放置ならセキュリティ面から考えてセッション切れるのは妥当なので正常処理として終了かと思います。放置した時間によって、必要なセッション保持時間かどうかは議論になるかなとは思います。
2の利用者がログインしないパターンは、ブックマーク機能や直接URL叩いていないかの確認し、ユーザが不正な操作をしていないか確認します。
3の正常にログインしているのパターンは、バグとも思われるので開発チームに処理が問題ないか、データの不整合は無いかの調査になります。
こういった感じで、運用チームはエラーメッセージと出たパターンによって対応が変わる感じかと思います。
新システムでも同じような動きをしたいので、旧システムと同じ現象のものは今のうちにメッセージ等で紐付けておいて、新システム稼働前からすぐに分かるようにしておきたい、といった感じです。
旧システムの調査と新システムの調査
新システムは旧システムのバージョンアップ的な作りではありますが、中身のコードは別々の開発チームで作られているので構造も全くの別物です。
エラーメッセージも旧システムで出ていたものを整理したりまとめたりしています。しかしながら、旧システムから新システムへのメッセージ紐付けにはかなり手間がかかりました。
理由としては以下のことが挙げられます。
- 機能修正により旧システム、または新システムしかない処理がある
- マイクロサービス化によるシステム内分散で、新旧の処理実装コードが1対1にならない
- 旧システムの設計書や情報が揃っていない
前述した方針は、メッセージを移行するだけの話です。
実際はその間にも案件として機能修正等いろいろ動いているので、それに沿った状態で対応しないといけなくなります。
例えば旧システムでは以下のようなエラーパターンがあったとします。処理やエラーメッセージは各クラスを準備して実行しているイメージです。
<旧システム>
初期画面 | 操作 | コード | エラーメッセージ | 原因 | 対応 |
---|---|---|---|---|---|
目次画面 | ユーザ情報画面へ遷移するボタン押下 | 401 | ユーザ情報が確認出来ませんでした。ログインしてください。 | 利用者が目次画面で長時間放置していた。 | 再度ログインして利用してもらう。 |
404 | ユーザ情報が確認出来ませんでした。 | DBから正常に取得出来なかった。 | 開発チームに調査依頼 | ||
ユーザ登録画面 | ユーザ情報を更新するボタン押下 | 400 | ユーザ情報が更新出来ませんでした。 | 更新前と更新後が同一情報 | 正常な反応 |
500 | ユーザ情報が更新出来ませんでした。管理者に問い合わせてください。 | DB登録時に接続エラー | 開発チームに調査依頼 | ||
ユーザ削除画面 | ユーザ情報を削除するボタン押下 | 404 | ユーザ情報が削除出来ませんでした。 | すでに削除されていた | 正常な反応 |
500 | ユーザ情報が削除出来ませんでした。管理者に問い合わせてください。 | DB登録時に接続エラー | 開発チームに調査依頼 |
これを新システムでは以下のようにまとめたとします。開発工数を減らすために同じ処理は共通クラスにまとめて、メッセージも同じのが出るようになった感じです。
<新システム>
初期画面 | 操作 | コード | エラーメッセージ | 原因 | 対応 |
---|---|---|---|---|---|
目次画面 | ユーザ情報画面へ遷移するボタン押下 | 5 | ユーザ情報確認エラー(共通メッセージ1) | 利用者が目次画面で長時間放置していた。 | 再度ログインして利用してもらう。 |
2 | DB接続エラー(共通メッセージ2) | DBから正常に取得出来なかった。 | 開発チームに調査依頼 | ||
ユーザ登録画面 | ユーザ情報を更新するボタン押下 | 5 | ユーザ情報確認エラー(共通メッセージ1) | 更新前と更新後が同一情報 | 正常な反応 |
2 | DB接続エラー(共通メッセージ2) | DB登録時に接続エラー | 開発チームに調査依頼 | ||
ユーザ削除画面 | ユーザ情報を削除するボタン押下 | 5 | ユーザ情報確認エラー(共通メッセージ1) | すでに削除されていた | 正常な反応 |
2 | DB接続エラー(共通メッセージ2) | DB登録時に接続エラー | 開発チームに調査依頼 |
実装コード的には、旧システムは各処理ごとにエラーチェックとメッセージをそれぞれで準備していましたが、メッセージやチェック内容がほぼ同じということもあり、新システムは共通的に処理できるようにまとめられました。実装的には3画面分の処理を1つにまとめたので工数減らして整理されてるように見えます。(細かいところ言うともっと色々とありますが、説明として簡略化してます。)
ただ、まとめたことにより運用チームから見るとエラーメッセージで状況が判別しづらくなってしまいました。
初期画面 | 操作 | 旧コード | 旧エラーメッセージ | 新コード | 新エラーメッセージ |
---|---|---|---|---|---|
目次画面 | ユーザ情報画面へ遷移するボタン押下 | 401 | ユーザ情報が確認出来ませんでした。ログインしてください。 | 5 | ユーザ情報確認エラー(共通メッセージ1) |
404 | ユーザ情報が確認出来ませんでした。 | 2 | DB接続エラー(共通メッセージ2) | ||
ユーザ登録画面 | ユーザ情報を更新するボタン押下 | 400 | ユーザ情報が更新出来ませんでした。 | 5 | ユーザ情報確認エラー(共通メッセージ1) |
500 | ユーザ情報が更新出来ませんでした。管理者に問い合わせてください。 | 2 | DB接続エラー(共通メッセージ2) | ||
ユーザ削除画面 | ユーザ情報を削除するボタン押下 | 404 | ユーザ情報が削除出来ませんでした。 | 5 | ユーザ情報確認エラー(共通メッセージ1) |
500 | ユーザ情報が削除出来ませんでした。管理者に問い合わせてください。 | 2 | DB接続エラー(共通メッセージ2) |
今まで404コードの「ユーザ情報が削除出来ませんでした。」のメッセージが出た場合、運用チームはすでに削除されていたユーザ情報に対して、削除処理しようとした時に起きたエラーだな、と判断することが出来ます。
対して、新システムで同様の現象が起きた時、「ユーザ情報確認エラー」と表示されます。
このメッセージだとデータ取得時なのか更新時なのか削除時なのかが分からなくなってしまっています。それら全てのパターンを確認する手間が増えることになります。
なぜこんなことが起きたのか
これが起きた原因としては、新システムを作る際に旧システムのメッセージを意識しなさ過ぎだったり、メッセージ処理をまとめたとしても判別する材料を少な過ぎにしてしまったり、などといろいろとありますが、本体動作中心の開発でログ対応にあまり手をかけられなかったことも一つの要因かなと思います。開発工数の兼ね合いもあるのでなかなか難しいところではありますが。。。
処理本体の開発工数に関してはまとめたことにより削減出来ましたが、その後運用時の調査時間やログ改修の工数は増す形にはなりそうなので運用後まで考えるとコストが増すことも考えられます。少なくとも新メッセージは旧メッセージのどれが対応するか、という確認作業がすでに発生してます。
どのように解消していくか
システムを作るにあたって、開発チームと運用チームで分かれることはそれなりにあるかと思います。またお互いどういった作業なのか分からないこともあるかと思います。出来るだけ双方の確認が細かく出来ることが理想ではあります。(体制によっては難しいこともありますが。。。)
先ほどのログメッセージに関しては共通にまとめたとしても、そもそもの情報量足りていないので、どの処理で起きたものなのか、エラーを起こしたパラメータはどういう状態なのか、などを付加してログの修正するのがまずは良さそうかなと思います。
1<ユーザ情報確認エラー(未ログイン、目次画面の場合)>
2{
3 code:5
4 message:ユーザ情報確認エラー
5 user_id:001
6 user_status:未ログイン
7 class:目次クラス
8}
9
10<ユーザ情報確認エラー(ログイン済み、ユーザ登録画面の場合)>
11{
12 code:5
13 message:ユーザ情報確認エラー
14 user_id:001
15 user_status:ログイン
16 class:ユーザ登録クラス
17}
18
19<ユーザ情報確認エラー(ユーザ情報無し、ユーザ削除画面の場合)>
20{
21 code:5
22 message:ユーザ情報確認エラー
23 user_id:001
24 user_status:null
25 class:ユーザ削除クラス
26}
メッセージ本文は要件に合わせつつ、ログ情報はログイン状態やエラー発生箇所など細かい情報を出来るだけ載せるのが整理しやすい形になるかなと思います。ただし、何でもかんでも情報を出し過ぎず、個人情報の扱いにも気をつけないといけません。
また、開発チームとして必要な情報はなんなのか、運用チームとして必要な情報はなんなのか、といったことを整理することも必要かなと思います。
開発チームとしては、以下の情報が必要かなと。
- メッセージは何が出ているか
- 発生源はどこか
- 何をしている時に起きたのか
- パラメータに不備は無いか、コードは正しいか
- 再発するような作りになっていないか
ログメッセージをもとにエラー発生源を特定し、エラーとして正しいのか、実装したコードが間違っているかを判断して対応していく感じになるかと思います。
対して運用チームとしては、以下の情報が必要かなと。
- メッセージは何が出ているか
- 何をしている時に起きたのか
- データが不整合になっていないか
- その後の運用にどのくらいの影響があるのか
- データの補正が必要か
- 対応後は正常に運用が続いているか
メッセージをもとにデータや利用の流れは合っているかを確認し、まずはその後の運用として正常に進められるかを確認しつつ、データやメッセージだけではエラーの原因が分からなければ開発チームに確認して、動作が正しいのかを判断するような感じになるかなと思います。
運用側はシステムの外側から見るような感じ、開発側はシステムの内側から見るような感じになり、それぞれ視点が違うのでここの連携がスムーズだとエラー対応もスムーズになるかと思います。
上記の例では1~3ケース程度のエラー紐付けでしたが、実際はエラーの種類はたくさんあり、紐づけるためには旧システムと新システムのエラーを全部見るような形になるのでけっこう大変です。エラー種類の抜け漏れ確認も出てくるのでシステム全体把握も必要になってきます。システム全体を把握し理解することは良いかと思いますが、それだけの時間やコストがかかるので出来る人も限られてきそうです。
対処として
現状としてはコストかけてでも全体のエラーの紐付け対応していくか、それとも新システム運用開始時に改めて1から開発と連携して対応パターンを作り上げていくか、迷いどころかなと思います。メンバー人数や体制にもよるので一概にこれ、といったものも無いかなと思います。
今回に関しては、まずは過去よく起きているエラーに絞ってのメッセージの紐付けをし、それをまとめた資料シートを作成していく流れになりました。それでも結局は新旧両方のシステム全体を見ないと整理出来ない状態なので、工数コストとしてはけっこうかかる感じとなりました。
実際に対応したことは以下の通りです。新旧両方のシステムの読み込みと運用の手順の把握が必要なので、かなり理解するまでの時間がかかる感じでした。
- 旧システムの把握
- 各APIの処理、設計書の確認
- API内のメッセージ処理確認
- 各APIがシステムとしてはどのようなオペレーションで実行されるか
- 新システムの把握
- 各APIの処理、設計書の確認(既存から不備があれば修正)
- API内のメッセージ処理確認
- 各APIがシステムとしてはどのようなオペレーションで実行されるか
- 旧システムでの運用チームの対応手順確認
- メッセージに対する実際の対応手順確認(実際にやっていた対応)
- 問い合わせ判断基準の確認(どういった時に開発チームと連携するか)
- 運用手順に合わせたメッセージ対比表の作成
- 新システムのメッセージ表作成
- メッセージ表に旧システムのメッセージの紐付きを追記
- 要件を満たしているかの確認
- 紐づかないメッセージの対応
- 必要に応じて実装の修正対応
- 各種設計書の更新
ここまでの情報を資料として開発チームが確認してまとめた感じになります。
ただ、実際に利用していくのは運用チームなので、ここでまとめた資料を運用チームが確認し、認識齟齬や連携の確認を随時していく形になります。
新システムもまだ稼働開始しているわけではないので、この先も資料シートの過不足調整等の作業は発生しそうです。
感想
実装や運用の仕方によってこのあたりの対応は変わっていくかと思うので一概には言えませんが、さまざまな仕様変更が随時起こる中、運用やログについても出来る限り実装時に考慮出来ると後々楽になるだろうなと思いました。
また、最初は考慮していても実装していくにつれて変更や修正なんかも起きるので、適宜連携も必要かなと。
そのためにも出来るだけ早い段階で、作ろうとする対象システムの仕様把握が出来ると良いかと思いました。
今回の対応に関しては、結果的にはかなり手間が増えたかなといった印象でした。
新システムのAPI本体実装時にもっと全体的に運用チームと連携取りながら調整していければもう少し楽にはなったのかなと思います。
開発時点では目の前の実装に追われやすいですが、次はもう少し視野を広げて対応出来れば全体のクオリティアップにも繋げられそうかなと思いました。
「ログを見ても現象や対応方法が分かりづらい」みたいなことは極力減らしていきたいです。
ライトコードでは、エンジニアを積極採用中!
ライトコードでは、エンジニアを積極採用しています!社長と一杯しながらお話しする機会もご用意しております。そのほかカジュアル面談等もございますので、くわしくは採用情報をご確認ください。
採用情報へ
元ファストフード店長代理のJava系ITエンジニア。 Webサイト系の開発や運用をいくらか経験し、 現在はAndroidアプリ開発を主に担当したり。 休みの日はゲームとか風景写真撮りに行ったりとかマラソンしたりとか。