自己紹介

opengl-8080
たまに Qiita で技術メモを書いたり
関西在住・SIer 勤務

はじめに

システム開発をしていると、いろいろな場面で不具合と遭遇する
当然、不具合は解決しなければならない
下に若手がついて一緒に開発をすることがあるが、不具合の解決方法が分からないと相談を受けることがよくある
経験が浅いと、不具合調査のために何から着手すればいいか分からない
ある程度パターン化された手順を踏むことで、多くの不具合は解決できるという経験的な認識がある
私がどういう手順で、何を考えながら不具合の解決を行っているかを整理・説明することで、若手の成長に繋がれば幸い

話すこと・対象者・前提

Java でシステム開発をしていて不具合に遭遇したときにどうやって解決するか
- 基本的な手順や考え方
- デバッグに役立つ知識（スタックトレースの読み方やデバッガの使い方）
- 不具合解決で気を付けること
1, 2年目くらいの若手が対象
- 不具合対応となると何からすればいいか分からない
- スタックトレースの読み方が分からない
- デバッガを使ってない（使えない）
Java の Web アプリ（サーバー側）で不具合が起こった場合を例として説明
- フロントエンドやDB・ビルドツールでの不具合は対象外
- ただし、考え方とかは技術要素や範囲が異なっても適用できる（はず）

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

何が起こっているかを正確に把握する

誰が、いつ、どういう条件で、どういう操作をしたら、何が起こったのか、問題（期待する結果との差）は何か
例
- お客様が、昨日の夕方、○○という条件で、××の検索を行ったら、検索結果が０件になった、本当なら１件出力されるはず
- 後輩が、さっき、ローカルで動かしている開発中のシステムで、Webアプリを起動したら、エラーが起こってアプリが起動しなかった、本当ならアプリが起動して欲しい

「正確に」把握することの重要さ

見切り発車で調査を開始すると、関係ないことを調べたりして時間を無駄にすることがある
例
- 「エラーになった」と言われたので例外がスローされているのかなとログを見に行ったが何も出力されてなかった（実際には入力値不正でエラーメッセージが出力されていた）
- 「アプリを起動したらエラーになった」と言われてログを見に行ったが何も出力されてなかった（実際にはコンパイルの時点でエラーになっており、起動すらしていなかった）
- 「アプリが動かない」と言われて色々しらべてみたが問題が再現せず。実は今ではなくメンテでDBを停止していた時間帯の話だった

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

不具合を再現させる

不具合の条件を正確に把握するため
- 不具合が起こる条件・起こらない条件を把握することで、原因が特定しやすくなる
原因調査をしやすくするため
- 再現できる = 何度でも試せる
- 何度も試して、様々な情報を収集できる
修正後に動作確認するため
- 修正後に不具合が解消していることを確実に検証できる

できればローカルで再現させる

ローカルであれば他の開発メンバーに影響しないので調査がしやすい
- デバッガで1ステップずつ動きを確認できる
- 様々な条件で何度も試せる

再現させられない場合

不具合が起こったときの状況をもう一度詳しく聞く
- どういう操作をしたのか
- どういう入力をしたのか
- 全く同じ条件で再現を試みているか？
不具合が起こる環境と起こらない環境はないか？
- もしある場合、２つの環境や操作内容に差はないか？
固定観念を捨てて、隅々まで条件が同じかチェックする
- 「当然同じだろう」と思っているところが案外違ったりする
- 例
  - 同じバージョンのソースを使っているか？
  - DBの中は同じ状態か？
  - 入力値は一字一句全く同じか？
  - etc...

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

例外がスローされる不具合の場合

Java の Web アプリで発生する不具合は大きく以下の２つに分けられる（気がする）
- 例外がスローされる不具合
- 例外がスローされない不具合
例外 = java.lang.Exception およびそのサブクラス
例外がスローされる不具合
- 非業務エラー
- システムが想定してないエラー
- 「障害が発生しました」「システム管理者に問い合わせてください」といったメッセージを出すような状態
- 例：ぬるぽ・DB通信エラーなど

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

例外の発生箇所を特定する

まずは例外がスローされた箇所（ソースコード上の場所）を特定する
普通はログに例外のスタックトレースが出力されている

スタックトレースの例

java.lang.RuntimeException: test
	at sandbox.debug.Fuga.fugaMethod(Fuga.java:6)
	at sandbox.debug.Hoge.hogeMethod(Hoge.java:7)
	at sandbox.debug.Main.main(Main.java:7)

スタックトレース

スタックトレース

java.lang.RuntimeException: test
	at sandbox.debug.Fuga.fugaMethod(Fuga.java:6)      (3)
	at sandbox.debug.Hoge.hogeMethod(Hoge.java:7)      (2)
	at sandbox.debug.Main.main(Main.java:7)            (1)

Java はスレッドごとにメソッドの呼び出しをスタックで管理している
- スタック = LIFOのデータ構造
例外を new すると、その時点のスタックの情報が例外に記録される
スタックトレースは、このスタックの情報を出力したもの
- トレース = trace = 追跡
- スタックを追跡するためのもの
スタックトレースを読むと、その例外を投げたスレッドがどのようにプログラムを通り、どこで例外をスローしたかが分かる

スタックトレースの読み方

初めて長大なスタックトレースを見るとビックリしてしまうかもしれないが、全部を読む必要は無い
「例外の発生箇所を特定する」という目的に対しては、一番重要なのはスタックトレースの先頭だけ
- スタックトレースの先頭行は、その例外が生成された場所
- 普通は throw new Exceptin() のように、生成と同時に例外をスローするので、例外が生成された場所＝例外がスローされた場所、になる

スタックトレースの読み方２（Caused by）

例外には 原因(cause) を設定できる
- その例外がスローされる原因となった別の例外
- コンストラクタで指定できる
原因が設定されている場合、スタックトレースには Caused by と書かれたものが追加される
- 原因のスタックトレースが別途出力される
原因は何重にも入れ子になっている可能性がある
- その場合、大本の原因にたどり着くまで再帰的に Caused by が出力される
- つまり、「例外の発生箇所を特定する」ためには、一番最後に出力された Caused by の先頭の行を見ればいい

スタックトレースの読み方・まとめ

「例外の発生箇所を特定する」ためには、

Caused by がない場合
- スタックトレースの先頭を見る

Caused by がある場合
- 最後の Caused by ブロックのスタックトレースの先頭を見る

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

例外の直接原因を特定する

例外がスローされた直接原因は、例外の型やメッセージからある程度推測できる
例外の型から推測
- NullPointerException: null参照が起こった
例外の型とメッセージから推測
- 例外が SocketException でメッセージが Socket is closed: 切断されたソケットで通信しようとした
- 例外が SQLException でメッセージが ERROR: syntax error at or near "\".: SQL に文法違反がある
いずれもスタックトレースに出力されている情報なので、スタックトレースをしっかり読むこと
- 英語でも怯えない
- 分からなければググるか機械翻訳にかければいい

ただし、例外の型やメッセージだけでは直接原因が分からないこともよくある

例外の発生箇所を確かめる

int length = obtainString().length();

発生した原因の例外が NullPointerException で、発生箇所を見ると上記のような実装になっていたとする
この場合、 obtainString の戻り値が null だったことが直接原因になる

直接原因で止まってはいけない

String string = obtainString();
int length = string == null ? 0 : string.length();

原因究明を直接原因の特定で終わってしまうと、上記のような修正で満足してしまう恐れがある
確かに NullPointerException は発生しなくなるが、そもそも obtainString が null を返すこと自体がおかしい場合、根本原因は解決していないことになる
他に obtainString を使っている場所で同じ問題が起こるかもしれない

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

例外の根本原因を特定する

発生した例外の直接原因がそのまま根本原因となることもあれば、そうでないこともある
根本原因でなかった場合、間違った対策を講じるおそれがある
必ず、特定した直接原因とは別に根本原因が無いか検討する必要がある
- 例
  - 設定値を参照しているところで NullPointerException が発生したが、そもそも設定値が null になること自体がおかしい
    - システムの設定に不備があることが根本原因だった
  - SQL のシンタックスエラーが出ているが、そもそもSQLは自動生成しているはずなのでシンタックスエラーになるのは不自然
    - SQLの自動生成ツールの設定不備が根本原因だった
  - HTTPの通信エラーになっているが、そもそもこの機能ではHTTP通信は必要ないはず
    - 実装が設計書通りになっていないのが根本原因だった

根本原因を特定する方法

正直難しい
- 場合によっては使っているフレームワークやミドルウェア、通信プロトコルなど様々な知識が必要となる
- 知識に関しては地道に経験を積んで、学んでいくしかないかと
使えるツール
- デバッガ
- 処理をステップ実行して変数の状態を確認できるので、原因究明がしやすい
- その他の方法
  - 机上デバッグ
    - 大変・ミスしがち
  - デバッグログを差し込む
    - 面倒・時間がかかる
- デバッガを使うのが一番の近道

デバッガの仕組み

JVM をデバッグ接続可能な状態で起動しておく
接続先の JVM を指定してデバッガ(IntelliJ とか Eclipse などが提供)を起動する
通信は、基本的には TCP で行われる（共有メモリとかもあるらしいが割愛）
- TCP 通信ができるのであればリモートマシン上で動いているJVMでも接続可能

デバッグ接続可能な状態でJVMを起動する

java -agentlib:jdwp=transport=dt_socket,server=y,address=8000,suspend=y ...

-agentlib:jdwp オプションを付けることでデバッグ接続が可能になる
- 検索すると -Xdebug および -Xrunjdwp を使った方法が出てくるが、これらは J2SE 5.0 より前の古い方法になる
各オプションの意味は以下の通り
- transport
  - 接続の方法
  - dt_socket ならソケット通信(TCP)
- server
  - y: デバッガからの接続受け付ける
  - n: デバッガに接続しにいく
- address
  - server=y なら、接続を待ち受けるアドレス
    - 上の例(address=8000)はポート番号だけを指定している
  - server=n なら、接続先のデバッガのアドレス
- suspend
  - デバッガとの接続が完了するまで JVM を一時停止するなら y

IDE でデバッガを起動する

IDE から直接アプリケーションを起動できる場合
- デバッグ起動を利用する

IntelliJ

Eclipse

IDE から直接アプリケーションを起動できない場合
- リモートデバッグを利用する
- Maven とかもデバッグできる

IntelliJ

Eclipse

デバッガの使い方

IntelliJ の場合で説明するが、Eclipse もだいたい同じ機能を提供している

ブレークポイントを設定する

行番号のところをクリックするとブレークポイントを設定できる
- もう一回クリックしたらブレークポイントを削除できる
プログラムの処理がブレークポイントに達すると、そこで処理が一時停止する
気になる処理の手前などにブレークポイントを設定しておいて、続くステップ実行を利用してプログラムの挙動を確認する

デバッガの見方

操作方法

ステップオーバー
- 処理を次の行に進める
- 1行ずつ処理を進めていきたいときに使う
ステップイン
- 現在の行から呼び出されるメソッドの中に入る
- 呼び出し先のメソッドの中まで処理を追いたいときに使う
ステップアウト
- スタックを１つ戻る（処理は進む）
- 現在のメソッドの処理を終わらせて呼び出し元へ戻りたいときに使う
再開(F9)・ステップオーバー(F8)・ステップイン(F7)はよく使うので、ショートカットを覚えておくと捗る

変数の値を管理する

デバッガに表示されている変数を右クリックすると、メニューが開く
変数の中身の値をコピーしたり、変数の中身の値を任意に書き換えたりできる
- デバッグ目的ではあまり書き換えは使わないが、無理やり null を代入して例外を発生させて挙動を見る、みたいなことができる

任意の式を実行する

デバッガの変数を表示しているところを右クリックしてメニューを開き、 [Evaluate Expression] を選択する

現在のスコープから参照できる変数を利用して任意の式を実行できる

条件付きブレークポイント

ブレークポイントを右クリックすると、 [Condition] で一時停止する条件を指定できる
デフォルトでは処理がブレークポイントに到達すると無条件に一時停止する
しかし、それだとループ中の特定の条件のときだけ一時停止したい、といった場合に非常に不便
条件を入れることで、例外が起こるであろう条件が満たされたときだけ処理を一時停止させるようなことができる

例外がスローされたら一時停止する

デバッガメニューのブレークポイントの管理(View Breakpoints)を選択し、管理用のダイアログを開く
左上の [+] から [Java Exception Breakpoints] を選択する

スローされたら一時停止させたい例外を選択する

以上の設定で、 NullPointerException がスローされたら、そのタイミング（スローしている行）で処理が一時停止するようになる
デフォルトで存在している [Any Exception] のチェックをオンにすると、任意の例外がスローされた場合でも一時停止が可能になる
例外が握りつぶされるなどしてスタックトレースが確認できない、みたいな悲しいケースで利用できる

フィールドの値が変更されたら一時停止する

フィールド宣言の行番号部分をクリックすると、目のアイコンのブレークポイントが作成される
デフォルトでは、フィールドに値が代入されたら処理が一時停止する
目のアイコンを右クリックしてメニューを表示し [Watch] > [Field access] を選択すると、フィールドにアクセスされたら処理を一時停止させられるようもできる

その他にも便利そうな機能が色々

Run to Cursor
- カーソル位置までステップを進める
Reset Frame
- フレーム（スタックの位置）を1つ前に戻す（処理をやり直せる）
Throw Exception
- 任意の例外をスローする

例外がスローされる不具合の場合まとめ

例外がスローされる不具合の場合は、まずは例外の発生箇所を特定する
- 例外の発生箇所はスタックトレースを見ればわかる
例外やメッセージ、発生箇所の情報から例外の直接原因を特定する
直接原因だけでなく、根本原因が無いか注意深く調査する
調査にはデバッガを使うのが近道

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

例外がスローされない不具合の場合

例外はスローされないが、システムが期待した動きをしていない状態
例
- 計算結果・検索結果が期待値と異なる
- 正しい値を入力しているはずなのに入力エラー扱いになる
- 表示されるべき画面項目が空になっている
- いつまで待っても画面が表示されない
- etc...
原因究明のアプローチが、例外がスローされる場合と異なる

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

問題の発生に関わる値を特定する

問題の発生に関わる何かしらの値が存在するはずなので、それを特定する
例
- 計算結果・検索結果が期待値と異なる
  - 計算結果、検索結果
- 正しい値を入力しているはずなのに入力エラー扱いになる
  - エラーとなった入力値
- 表示されるべき画面項目が空になっている
  - 画面項目の値
- いつまで待っても画面が表示されない
  - レスポンス

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

問題の値を処理している箇所を特定する

問題の値を処理している箇所があるはずなので、その場所を特定する
入口または出口から辿って行って、問題の値を処理しているところを見つけ出す
- 入口
  - リクエストを受け付ける場所
- 出口
  - レスポンスを返す場所
- Spring MVC でいうとコントローラのメソッド
例
- 検索結果があるはずなのに無い
- レスポンスに書き出された検索結果の値が問題なので出口の方から辿る
- レスポンスを返しているところで検索結果が期待通り設定されているか確認する
  - →設定されていない
- なぜ設定されていないのかを確かめるため、検索結果を設定している箇所を実装をさかのぼって見つけ出す
デバッガを使って、問題の値がどのタイミングで変な状態になったのかを特定する
- 机上デバッグだと勘違いする恐れがあるので、デバッガを使って確実に調査する

@GetMapping("/hello")
public String hello(Model model, @RequestParam String condition) {
    // 2. デバッガで見ると、この時点で空のリストが返されている！
    List<Result> result = service.search(condition);
    
    // 1. 検索結果(result)が設定されている箇所を特定！
    model.addAttribute("result", result);
    return "hello";
}

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

問題の値が生成される直接原因を特定する

問題の値が設定されている箇所が特定できたら、なぜ変な値が設定されてしまったのか直接原因を特定する
例
- 問題 → 検索結果が空
- 直接原因 → DBアクセスの結果が空だったため

public List<Result> search(String condition) {
    // 入力値チェックとか...

    // DB検索 (デバッガで見ると、この時点で空を返している！)
    List<HoegEntity> list = dao.find(condition);

    // 変換して返却
    return convert(list);
}

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

問題の値が生成される根本原因を特定する

例外がスローされる不具合の場合と同様に、問題の直接原因が分かったら次は根本原因が無いか調査する
例
- 問題
  - 検索結果が空
- 直接原因
  - DBアクセスの結果が空だったため
- 根本原因の調査
  - SQL に問題はなさそう
  - 検索条件をデバッガで確認したら空になっていた！
  - なぜ検索条件が空になるのかデバッガで辿った結果、そもそも HTTP リクエストのパラメータに乗せられていなかった！
こちらも、原因究明にはデバッガの利用が効率的

例外がスローされない不具合の場合・まとめ

発生している不具合に直接関係している値を特定する
その値が生成されている箇所を特定する
- システムの入口・出口から辿っていく
- デバッガを使って確実に調べるのが良い
問題の値が、なぜ期待していない値になっているのかの直接原因を特定する
根本原因を特定する

ざっくりとした流れ

何が起こっているかを正確に把握する
不具合を再現させる
例外がスローされる不具合の場合
- 例外の発生箇所を特定する
- 例外の直接原因を特定する
- 例外の根本原因を特定する
例外がスローされない不具合の場合
- 問題の発生に関わる値を特定する
- 問題の値を処理している箇所を特定する
- 問題の値が生成される直接原因を特定する
- 問題の値が生成される根本原因を特定する
対策を講じる
不具合が解消していることを確認する

対策を講じる・不具合が解消していることを確認する

根本原因が特定できたら、どう対処するかを検討する
検討内容を適用してみて、不具合が解消していることを確認する
このとき、不具合の再現ができていると確認を確実に実施できる

失敗例

報告された不具合内容から原因を推測して調査を開始
- 関係ないところを調べて時間を浪費
根本原因を推測するも、確証を得ずに対策を検討
- 推測内容に誤りがあり、時間が無駄に

思い込みは最大の敵

不具合解決において 思い込み は最大の敵
- タイポはないはず
- 設定値は正しい値が設定されているはず
- 利用している環境は同じはず
- etc...
いずれのステップも「思い込み」を排除して「事実」を積み重ねていく
- デバッガを使って処理の流れ、変数の値を確実にチェックする
一日置いて見直してみたら単純なタイポが原因だった、なんてことは誰もが経験する
- 思い込んでいる最中は、どうしても気づけなくなるもの
- 「思い込んでいる」可能性を考慮して、くだらないと思えることであっても１つずつ問題ないことを確認するくらいがちょうどいい

　　　　　　↓

面倒かもしれないが、些細なことも一つずつ確実に確認しながら進めることが不具合解決の一番の近道

まとめ

まずは起こっていることを正確に把握する
不具合を再現させる
まずは直接原因を特定する
- 例外のスタックトレースを読めば直接原因は簡単に特定できる
- 例外がスローされない場合は問題の値を処理している箇所を特定する
直接原因が分かったら、必ず根本原因まで掘り下げる
- 特定にはデバッガの利用が楽
根本原因が分かったら対策を講じ、不具合が解消されることを確認する
いずれのステップも「思い込み」を排除して「事実」を着実に積み上げていくことが一番の近道