JJUG CCC 2015 Fallに行って、スレッドダンプについて考えてみた

先日、JJUG CCC 2015 FallというJavaのイベントに行ってきました。

いくつかセッションに参加しましたが、山本裕介さんのセッション「苦手克服!例外スタックトレースから読み解くバグ」について自分なりに調べてみました。

このセッションは、例外とは何か?エラーとは何か?から入って、スタックトレースの読み方まで話されていて経験の浅い私でもかなり入りやすかったです。

■エラーとは?

ざっくり言うと不具合です。エラーには大きく分けて3種類あります。

エラーの種類、説明、気づく方法。

1. 文法エラー(syntax error)

→文法間違っているよ!(例:閉じ括弧「}」がない、セミコロン忘れなど)

→コンパイルエラーが発生して失敗する。

2. 実行時エラー(runtime error)

→実行中に想定外の事態発生!動作の継続できない。(例:メモリ不足→OutOfMemoryErrorなど)

→実行すると途中で強制終了する。

3. 論理エラー(logic error)

→Javaの文法には問題はないが、記述した処理内容に問題あり。(例:1 + 2の結果を出力する処理で期待値は3であるが、5と出力される)

→実行すると想定外の処理結果になる。

■例外とは?

ざっくり言うと、想定外の事態のことです。

例えば、

・読み書きしているときに何か起きた(IOException)

・nullが入っている変数を利用しようとした(NullPointerException)

などがあります。

■例外とエラーの違いは?

例外とエラーは同じと思っている人(私もそうでした)がいるかもしれませんが、違います!

Errorは、回復見込みがない、致命的な状況。打つ手はないのでcatchは不要。

Exceptionは、回復見込みがある状況。Exceptionの中でもcatchが必須でないものをRuntimeExceptionといいます。

また、継承元が異なります。

Errorの継承関係は、java.lang.Objec - java.lang.Throwable - java.lang.Errorとなっています。(OutOfMemoryErrorなど)

Exceptionの継承関係は、java.lang.Object - java.lang.Throwable - java.lang.Exceptionとなっています。(IOExceptionなど)

RuntimeExceptionの継承関係は、java.lang.Object - java.lang.Throwable - java.lang.Exception - java.lang.RuntimeExceptionとなっています。(NullPointerExceptionなど)

■スレッドダンプ

Java の各スレッドがそれぞれ何をしているか確認できるもの。スナップショット。

スレッドダンプを取得すると、取得したときにJVM上でどんな処理が実行されているかわかります。

スレッドダンプは、間隔をあけて何度か取得してください。(最低3回)各スレッドの状態遷移を調べることができて調査の幅が広がります。

■スタックトレース

スタックトレースとは、スタックの中身を出力したもの。最初に呼び出されたメソッドから順に重ねていったもの。

スタックトレースを出力することで、どこで例外が起きたかわかるかもしれません。

■スレッドダンプの吐き出し方

Intellijでのスレッドダンプの吐き出し方は、このアイコンを探してクリックするだけです。

ターミナルで確認したいよ!って方のために「jstack」コマンドもあります。jpsコマンドを先に実行してください。

jpsコマンド:Javaのプロセス一覧を表示する。プロセスIDとプロセス名を出力。「-l」オプションを指定するとパッケージ名も出力します。その他のオプションは割愛。

jstackコマンド:実行中のJavaプロセスのスレッド状態を取得する。

■例外スタックトレースを読む

今回は、セッションのタイトルでもあった例外スタックトレースに焦点をあててみようと思います。

次のNumberFormatException(これint型に変換できなくね?というException)が起きるプログラムを例に進めていきましょう。

package jjug;

public class stackTrace {
   public static void main(String[] args) throws Exception{
      test1();
   }
   public static void test1() throws Exception{
      try {
         String nullStr = null;
         int parseStr = Integer.parseInt(nullStr);
         System.out.println(parseStr);
      } catch (NumberFormatException e) {
         throw new NumberFormatException("method test1");
      }
   }
}

スレッドダンプ次のようになります。

Exception in thread "main" java.lang.NumberFormatException: method test1
    at jjug.stackTrace.test1(stackTrace.java:15)
    at jjug.stackTrace.main(stackTrace.java:6)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)

Exception in thread "main" java.lang.NumberFormatException: method test1

1行目からは

・スレッド名→Exception in thread "main"

・例外種別→java.lang.NumberFormatException

・メッセージ→method test1

が読み取れます。

at jjug.stackTrace.test1(stackTrace.java:15)
    at jjug.stackTrace.main(stackTrace.java:6)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)

2行目以降は、スタックトレースが読み取れます。

1番下の行が1番最初にスタックに積まれたもので、上に行くにつれて後から積まれたものになっていきます。

参考:

この国では犬がコードを書いています http://enk.hatenablog.com/entry/2014/09/22/001303

■おまけ

Exceptionチェーンについて。Exceptionチェーンがなしの例外処理は、例外の情報が失われてしまって。

どこで例外が起きているのか見つけにくくなります。

これは、Exceptionチェーンなしの例外処理の例です。

package jjug;

public class exChainSample {
   public static void main(String[] args) throws RuntimeException{
      try {
         String nullStr = null;
         test1(nullStr);
      } catch (NumberFormatException e) {
         throw new RuntimeException();
      }
   }
   public static void test1(String nullStr) throws NumberFormatException{
      try {
         int nullParse = Integer.parseInt(nullStr);
      } catch (NumberFormatException e1) {
         throw new NumberFormatException();
      }
   }
}

スレッドダンプはこのようになります。

Exception in thread "main" java.lang.RuntimeException
    at jjug.exChainSample.main(exChainSample.java:11)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)

17行目でExceptionが発生しているはずなのに、11行目でエラーですと。このように情報が消えてしまうのです。

Exceptionチェーンありの例外処理をしたプログラムがこちらです。11行目だけ抜粋。eを引数に渡すだけです。

throw new RuntimeException(e);

スレッドダンプがこちらです。

Exception in thread "main" java.lang.RuntimeException: java.lang.NumberFormatException
    at jjug.exChainSample.main(exChainSample.java:11)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)
Caused by: java.lang.NumberFormatException
    at jjug.exChainSample.test1(exChainSample.java:19)
    at jjug.exChainSample.main(exChainSample.java:9)
    ... 5 more

今度はちゃんと19行目のNumberFormatExceptionも拾ってくれます。

流れとしてはこんな感じでしょうか?

1. 17行目でNumberFormatException発生

2. 18行目でcatchして、19行目でthrow

3. 10行目でNumberFormatExceptionをcatch。(eにExceptionの内容が。。。)

4. 11行目でNumberFormatExceptionの内容とともにRuntimeExceptionを投げる。

これでスタックトレースを読むのが楽しみになりましたよね?