Spring BootでのAOPを利用したログ出力

はじめに

　以前作成したwebアプリで、ログをファイル出力できるように改良した際に学んだことをまとめました。

共通処理を意識していないコードの例

　例として、ユーザをデータベースに追加する処理を用意しました。データベースへの追加のほかに、ログを表示するコードが書かれています。

RegistrationService.java

@Service
public class RegistrationService {
	
	private final RegistrationMapper registrationMapper;
	
	private final PasswordEncoder passwordEncoder;
	
	private static final Logger logger = LoggerFactory.getLogger(RegistrationService.class);
	
	public RegistrationService(RegistrationMapper registrationMapper,
			                   PasswordEncoder passwordEncoder) {
		this.registrationMapper = registrationMapper;
		this.passwordEncoder = passwordEncoder;
	}
	
	@Transactional(readOnly = false)
	public void insertAccount(RegisterForm form) {
        logger.info("ユーザ登録メソッド実行開始:" + form.getUserName()); //本質ではない

		form.setPassword(passwordEncoder.encode(form.getPassword()));
		Account account = new Account(form.getUserName(),form.getPassword(),form.getMail(),"ROLE_USER");
		registrationMapper.insertAccount(account);

        logger.info("ユーザ登録メソッド実行終了:" + form.getUserName()); //本質ではない
	}

}

　もしもログの表示形式を変更する場合、本質ではないコードを一つ一つ修正しなければなりません。また、他のServiceクラスでも同じような処理を記述していたらそちらも修正せねばならず、時間が掛かってしまいます。修正漏れがあった場合は、思わぬ不具合を起こす要因にもなり得ます。

・ 本来共通化できる処理を、複数のクラスに書いてしまっている
・ クラスが増加するにつれて修正するべき箇所が増える
　これらの問題を解決できる手法が、AOP(アスペクト指向プログラミング) です。

AOP(アスペクト指向プログラミング)

　複数のクラスに存在する共通処理を1つにまとめて管理できるように設計・実装する手法のこと。対象のクラスへ、共通的な機処理を追加することが出来る。

AOPの用語

用語	意味
Aspect	実装したい共通処理のこと。 お堅い言葉で言うと、「横断的な関心事」
Join Point	共通処理を注入する部分。 Spring AOPの場合は、メソッド実行時。
Advice	共通処理によって実行されるコード。 アノテーションによって、実行タイミングを指定できる。
Pointcut	実行対象のJoinPointを選択する表現。 例)within(com.dining.boyaki.controller.*)
Target	Pointcutで指定した、AOPによって処理フローを変更したいオブジェクト。 ServiceクラスやControllerクラスのこと。

AOPの仕組み

　Spring 徹底入門を参考に、AOPの仕組みを図で表してみました。Application Contextとか端折ってますがご了承ください。DIについての説明はここでは省略いたします。

　AOPのクラスには@Aspectと@Componentを付与する必要があります。
　DIコンテナに管理されているBean(@Serviceとか@Controllerとか)をtargetとしてProxyオブジェクトが作成され、Adviceが適用されるイメージです。

Adviceの実行タイミングを指定するアノテーション

アノテーション	Adviceの実行タイミング
Before	メソッド実行の前
After	メソッド実行の後
AfterReturning	メソッドの正常終了後
AfterThrowing	メソッドで例外がスローされた後
Around	メソッド実行の前後

　AfterReturningはメソッドで例外がスローされた場合は実行されず、AfterThrowingはメソッドが正常終了した場合は実行されませんのでご注意ください。

Pointcut式の種類

指示子	指定方法	例
execution	メソッド名のパターン	"execution(* com.sample.spring.service.*Serivce.find*(..))" →com.sample.spring.service.○○Serviceクラスのfind△△メソッドが対象
within	クラス名のパターン	"within(* com.sample.spring.service.*)" →com.sample.spring.service直下のクラスが対象
bean	DIコンテナで管理しているBean名	"bean(*Controller)" →DIコンテナで管理されていて、Bean名が○○Controllerのメソッドが対象

　Pointcutの書き方については、こちらが大変参考になりました。

Springでよく利用されているAOPの例

　メソッドに付与することでAOPが有効になるアノテーションの例です。
1.トランザクション管理(@Transactional)　

RegistrationService.java

    @Transactional(readOnly = false)
	public void updateAccount(AccountInfoForm form) {
    //データベース更新更新
    }

2.認可処理(@PreAuthorize)

sample.java

    @GetMapping("/admin")
    @PreAuthorize("hasRole('ROLE_USER')")
	public String showAdminIndex(Model model) {
		return "Admin/AdminIndex";
	}

ログ出力

　Spring Bootのログは基本はコンソールに出力されますが、logback-spring.xmlに設定を記述することでファイル出力が可能となるそうです。
(手持ちの書籍の方には詳しく説明されておらず、現在もweb上のドキュメントや記事で勉強中です)

コード

LoggingAdvice.java

LoggingAdvice.java

@Aspect
@Component
public class LoggingAdvice {
	
	private final Logger logger;

	public LoggingAdvice() {
	        this.logger = LoggerFactory.getLogger(getClass());
	}
	
	@Before("within(com.dining.boyaki.controller.*)")
	public void controllerInputLog(JoinPoint jp) {
		
		String logMessage = "[" + getSessionId() + "] " + getUserName() + getClassName(jp) 
				                + getSignatureName(jp)  + getArgs(jp);
		logger.info(logMessage);
	}
	
	@AfterReturning(pointcut = "within(com.dining.boyaki.controller.*)",
			        returning = "returnValue")
	public void controllerOutputLog(JoinPoint jp,Object returnValue) {
		String logMessage = "[" + getSessionId() + "] " + getUserName() + getClassName(jp)
				                + getSignatureName(jp)  + getReturnValue(returnValue);
		logger.info(logMessage);
	}
	
	//メソッドを実行したユーザ名を取得
	private String getUserName() {
		Authentication auth = SecurityContextHolder.getContext().getAuthentication();
		
		if(auth.getPrincipal() instanceof AccountUserDetails) {
			AccountUserDetails details = (AccountUserDetails) auth.getPrincipal();
			return details.getUsername() + ':';
		}else {
			return "???:";
		}
	}
	
	//セッションIDの取得
	private String getSessionId() {
		//ServletRequestAttributes：サーブレットリクエストと HTTP セッションスコープからオブジェクトにアクセスできる
		//RequestContextHolder：RequestAttributesオブジェクトの形式でスレッドローカルにWebリクエストを持つ
		//RequestAttributes：リクエストに関連付けられたオブジェクトにアクセスするためのインタフェース
        return ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest().getSession().getId();
    	}
	
	//実行されたクラス名の取得
	private String getClassName(JoinPoint joinPoint) {
		String packageName = joinPoint.getTarget().getClass().toString();
		String[] className = packageName.replace(" ", "\\.").split("\\.");

        return className[className.length - 1];
    	}
	
	//メソッド名の取得
	private String getSignatureName(JoinPoint joinPoint) {
        return "." + joinPoint.getSignature().getName();
   	 }
	
	//引数の値を取得
	private String getArgs(JoinPoint joinPoint) {
		Object[] arguments = joinPoint.getArgs();
		List<String> argumentStrings = new ArrayList<String>();

		Arrays.stream(arguments).map(s -> Objects.toString(s)) //mapは、集合データ内の各要素を変換するメソッド 
		                        .forEach(s -> argumentStrings.add(s));
		return " args :" + String.join(",", argumentStrings);
	}
	
	//返り値を取得
	private String getReturnValue(Object returnValue) {
        if(returnValue != null) {
        	return " value:" + returnValue.toString();
        }
        return " value:null";
    }

　AOPクラスのコードだけ記載します。logback-spring.xmlは、こちらの技術ブログを参考に作成しました。

結果

　コンソール上で確認すると、こんな感じでログが出力されます。
ユーザ名、リクエストを受けたコントローラのメソッド、引数などが表示されました。

　アプリのURLからアクセスしたら、webサーバ上にログファイルが生成されており、出力内容も問題ありませんでした。

　今後は、ログファイルをAWSのS3にアップロードできるようなシェルスクリプトを作成し、更なる改良を図りたいと思います。

参考文献

書籍：Spring 徹底入門