ループ中で例外を握りつぶしていたせいで物凄い回数の例外生成が走り、サーバのCPUが100％に張り付く現象に遭遇したので備忘録も兼ねて書いていきます。
ちなみにJDK8です。
まずはこちらのコードをご覧ください。
public static <T extends Enum<T>> T valueOf(Class<T> src, String val) {
T elm;
try {
elm = Enum.valueOf(src, val);
} catch (IllegalArgumentException iae) {
elm = null;
} catch (NullPointerException npe) {
elm = null;
}
return elm;
}
このコードは引数で渡されたEnumクラスの要素をvalue指定で取得して返却しています。
特筆すべきはtry-catchでIllegalArgumentExceptionとNullPointerExceptionを握りつぶしている点です。
java.lang.Enum.valueOfは以下の場合に例外をスローします。
- 第二引数がnullだった場合 ⇒
NullPointerException - 第一引数のEnumに第二引数のvalueに該当する要素が存在しない場合 ⇒
IllegalArgumentException
今回はこれをループ内で呼び出したらどうなってしまうのかという話です。
例外生成はそれ自体コストの高い処理ですが、spring等のWebアプリケーションフレームワークを使っている場合はスタックトレースがかなり深くなるため、その分例外の生成コストも上がります。
単体でもコストの高い例外生成を数万、あるいは数十万単位で発生させるとどうなるか見ていきたいと思います。
再現実験
前提条件
public class EnumUtil {
public static <T extends Enum<T>> T valueOf(Class<T> src, String val) {
T elm;
try {
elm = Enum.valueOf(src, val);
} catch (IllegalArgumentException iae) {
elm = null;
} catch (NullPointerException npe) {
elm = null;
}
return elm;
}
}
public enum TestEnum {
HOGE;
}
public class TestLogic {
public void execute(int num, int maxStack, int loopCount) {
if (num == maxStack) {
for (int i = 0; i < loopCount; i++) {
EnumUtil.valueOf(TestEnum.class, "HUGA");
}
} else {
Main.execute(num + 1, maxStack, loopCount);
}
}
}
public class Main {
public static void main(String args[]) {
long startTime = System.currentTimeMillis();
TestLogic logic = new TestLogic();
logic.execute(Integer.valueOf(args[0]), Integer.valueOf(args[1]), Integer.valueOf(args[2]));
long endTime = System.currentTimeMillis();
System.out.println("処理時間：" + (endTime - startTime) + " ms");
}
}
Enumを処理するクラスでは、前段の通り例外を握りつぶして処理を続行しています。
TestLogicでこの処理を呼び出す際、わざとEnum.valueOfでIllegalArgumentExceptionが発生するような引数を渡すことで、状況を再現しています。
またスレッドスタックの深さを再現するため、メソッドを指定回数再帰呼び出ししています（今回は遭遇した事例に合わせて140）。
結果
| ループ回数 | 処理時間（ms） |
|---|---|
| 10000 | 65 |
| 50000 | 360 |
| 100000 | 667 |
| 200000 | 1248 |
| 300000 | 1878 |
| 400000 | 2481 |
| 500000 | 3093 |
| 600000 | 3723 |
| 700000 | 4281 |
| 800000 | 4920 |
| 900000 | 5494 |
| 1000000 | 5970 |
100000回ごとに600ms程度のオーバーヘッドが発生しているのがわかります。
ちなみに例外を生成しないコード（「EnumUtil.valueOf(TestEnum.class, "HUGA");」を「EnumUtil.valueOf(TestEnum.class, "HOGE");）に修正して実行すると以下のようになります。
| ループ回数 | 処理時間（ms） |
|---|---|
| 10000 | 4 |
| 100000 | 10 |
| 400000 | 11 |
| 700000 | 11 |
| 1000000 | 14 |
当然ですが、例外生成のオーバーヘッドがない分はやいですね。
まとめ
例外を握りつぶすというのは結構ありがちなシチュエーションかと思いますが、それをループ中でやってしまうと今回のように処理時間がどんどん増えて、サービスの運用に支障をきたすかもしれません。
（今回は単純化された環境で試しましたが、実際のサービスではもっと処理が複雑だったり複数のスレッドが同時に動いていたりするので、私が遭遇したようにCPUが100％に張り付くといった致命的な結果をもたらす恐れがあります）
今回例示したEnumUtilのような共通クラスは結構何気なく呼び出してしまいがちですが、それが性能面で問題を引き起こす可能性があるかという視点も大切だなあと改めて感じました。