Javaでエラー発生時に原因のメソッドの引数の値までログに出力したい

2022 7/28

2022/06/26 2022/07/28

前置き

Spring Bootを使用して解決します。

Exception.printStackTrace()はエラー発生メソッド名と行までしか教えてくれない

Javaでエラーが発生した際、printStackTraceを使用してエラー原因を出力しても、エラーの発生したメソッド名と、ファイルの何行目でエラーが発生したのかまでしか教えてくれません。この状態だと、明記された行の中で複数の変数を使用している場合には具体的にどの値に問題があってエラーとなったのかがわかりません。本番環境で詳細な値をログに出してしまうことはセキュリティ的によろしくないですが、デバッグ時には早くエラーの内容を理解したいですよね。

メソッド内のデータ取得で問題が発生している場合もありますが、まずは少なくともエラー発生メソッドの引数の値を全て見たい。SpringBootを使用しているのであれば、SpringAOPで引数の値を全部ログに出力することができます。

AOP（アスペクト指向プログラミング）とは？

Aspect Oriented Programmingは、「オブジェクト指向プログラミング」のように、プログラミング方法の概念の1つです。「プログラムのモジュール性を高める」そうです。

わかりやすく言うと、プログラム各所で同じように使いたい共通処理をそれぞれの処理から抜き出し、横断的(Aspect)にそれぞれの処理が抜き出された共通処理を呼び出し、実行します。今回のように同じ形でログを出力したい時に使えるみたいですね。

SpringAOPの使い方

前置き

今回はorg.aspectjを使います。
SpringAOPを使いたい時の説明は書いていません。こちらからdependenciesを追加して使えるようにしてお好きなようにコードを組んでください。
今回はControllerクラス全てに使う共通処理を書く例です
Controllerクラスには手をつける必要はありません

1：AOPクラスを用意する

実は追加する処理はこれだけです。

package project.mine.aop;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.CodeSignature;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class AopSample {

    // 「Controller」がクラス名につく全てのクラスに対して注入する
    @Around("execution(* *..*.*Controller.*(..))")
    public Object aroundAop(ProceedingJoinPoint joinPoint) throws Throwable {

        try {
            System.out.println("[Around]メソッド開始:" + joinPoint.getSignature());
            // メソッド実行
            Object result = joinPoint.proceed();
            System.out.println("[Around]メソッド終了:" + joinPoint.getSignature());
            return result;
        } catch(Exception e) {
            System.out.println("[Around]メソッド異常終了:" + joinPoint.getSignature());
            // 異常終了の場合のみ、引数の値を全て出力します
            // メソッドの引数の名前
            String[] methodArgNames = ((CodeSignature) joinPoint.getSignature()).getParameterNames();

            // メソッドの引数の値
            Object[] methodArgValues = joinPoint.getArgs();

            // 「メソッドの引数の名前=メソッドの引数の値」形式で表示する
            for (int i = 0; i < methodArgNames1.length; i++) {
                System.out.print(methodArgNames1[i] + "=" + String.valueOf(methodArgValues1[i]) + " ");
            }
            System.out.print("\n");
            e.printStackTrace();
            throw e;
        }
    }
}

解説

@Around("execution(* *..*.*Controller.*(..))")と指定し、Controllerクラスのいずれかのメソッドが起動した時に必ず呼び出される処理を書きました。

@Aroundはメソッド起動前後に処理を書くことができます。同様に@Beforeはメソッド起動前に、@Afterはメソッド起動後（処理実行後）に行いたい処理がある時に使います。今回はメソッド起動前にどの機能が動くか、メソッド処理後にどの処理が終わったかを出力したいため、メソッド前後どちらも処理が欠ける@Aroundを使用しました。

上のロジックだと、Controllerクラスのいずれかのメソッドが呼び出され動く際

処理実行前に「[Around]メソッド開始:xxxController.xxMethod(arg1の型, arg2の型, arg3の型)」が標準出力に出力されます
処理が正常終了の場合、終了時に「[Around]メソッド終了:xxxController.xxMethod(arg1の型, arg2の型, arg3の型)」が出力されます
処理が異常終了の場合、終了時に「[Around]メソッド異常終了:xxxController.xxMethod(arg1の型, arg2の型, arg3の型)」「arg1=value1, arg2=value2, arg3=value3」が出力されます
引数の数、名称、値はそれぞれのメソッドと使用した条件に合わせて勝手にうまいこと表示してくれます