Aspect Logger Sample

package com.sil.docsflow.common.support.spring;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * Created with IntelliJ IDEA.
 *
 * @author: ihoneymon
 * Date: 14. 1. 10
 */
public class AspectLogger {
    private static final Logger logger = LoggerFactory.getLogger(AspectLogger.class);

    public void afterThrowingAdvice(JoinPoint joinPoint, Throwable exception) {
        String signatureInfo = getSignatureInfo(joinPoint);
        String exceptionMessage = exception.getMessage();
        if (exceptionMessage == null || exceptionMessage.trim().length() < 1) {
            exceptionMessage = "oops! occured exception";
        }

        logger.debug("=>> ### " + signatureInfo + " : " + exceptionMessage, exception);
        logger.warn("<<= ### " + signatureInfo + " : " + exceptionMessage);
    }

    public Object aroundAdvice(ProceedingJoinPoint joinPoint) throws Throwable {
        String signatureInfo = getSignatureInfo(joinPoint);

        logger.debug("=>> " + signatureInfo);
        Object retVal = joinPoint.proceed();
        logger.debug("<<= " + signatureInfo + (retVal != null ? " : " + retVal : ""));

        return retVal;
    }

    private String getSignatureInfo(JoinPoint joinPoint) {
        String signatureName = joinPoint.getSignature().getName();
        String className = joinPoint.getTarget().getClass().getSimpleName();

        StringBuilder sb = new StringBuilder();
        sb.append(className).append('.').append(signatureName).append('(');

        Object[] args = joinPoint.getArgs();
        if (args != null && args.length > 0) {
            for (int i = 0; i < args.length; i++) {

                if (args[i] instanceof String) sb.append('\"');
                sb.append(args[i]);
                if (args[i] instanceof String) sb.append('\"');

                if (i < args.length - 1) {
                    sb.append(',');
                }
            }
        }
        sb.append(')');

        return sb.toString();
    }
}

일반적으로 사용가능한 Aspect Logger.

이를 사용하기 위한 logging.xml

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:aop="http://www.springframework.org/schema/aop"
       xsi:schemaLocation="http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-3.2.xsd
        http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.2.xsd">

    <aop:aspectj-autoproxy/>

    <bean id="loggingAspect" class="{package}.AspectLogger"/>
    <aop:config>
        <aop:aspect ref="loggingAspect">
            <aop:pointcut id="loggingPointCut" expression="execution(* {package}.{class}({method})) $amp;$amp; !execution(* {package}.AopLogger(..))"/>
            <aop:around method="aroundAdvice" pointcut-ref="loggingPointCut"/>
            <aop:after-throwing method="afterThrowingAdvice" pointcut-ref="loggingPointCut" throwing="exception"/>
        </aop:aspect>
    </aop:config>
</beans>

위의 설정에서 빼먹지 말 것은, <aop:pointcut id="loggingPointCut" expression="execution(* {package}.{class}({method})) $amp;$amp; !execution(* {package}.AopLogger(..))"/> 에서 !execution 이다. AspectLogger 자신을 포인트컷에서 제외시켜주어야 한다. 다른 곳에서는 별다른 문제가 없었는데… 지금 개발하고 있는 프로젝트에서 끊임없이 자신을 물고 들어가면서 로그를 찍다가 예외들을 뱉는다. 그래서 묻어두었다가 logger를 입력하는 것이 귀찮아서 다시 AspectLogger를 꺼내어 들었다.

요즘 많이 사용되는 AOP Logging. 현재 작업 중인 프로젝트에서도 사용중인데, 최근 기능을 추가하면서 문제가 발생했다.


● 문제발생

현재 사용중인 프로젝트에서도 AspectLogging 기법을 사용했다. 그런데, class cast를 하는 과정에서 지속적으로

Exception in thread "main" java.lang.ClassCastException: $Proxy11 cannot be cast to classA

라고 하는 문제가 발생하면서 로깅클래스에서 동작이 멈추는 증상이 나타났다. 물론…
AOP측에서 이에 대한 예외처리를 제대로 했으면 별문제가 없었겠지만,


● 문제요인

문제가 발생하는 부분을 유심히 살펴봤다. 스프링의 ReloadableResourceBundleMessageSource를 확장extends하여 간단한 메소드를 추가한 ResourceBundleMessageSource클래스로 class casting을 하는 부분에서 문제가 발생하고 있었다.


● 힌트

이 문제가 왜 생겼는지 인터넷 검색에 들어간다.

그러다가 발견한 힌트!

classcastexception-proxy-cannot-be-cast-to-using-aop - Stackoverflow

제일 마지막 부분에

a good article about proxy creation in Spring

이 글을 보고 깨달음을 얻었다.


● 해결책

  1. BundleMessageSource 라고 하는 인터페이스를 만들고, ResourceBundleMessageSource 클래스에서 implements 로 구현한다고 선언.
  2. ResourceBundleMessageSource 를 class casting 하는 부분을 BundleMessageSource 로 변경하였다.
  3. OK~!

● 정리

… proxy에서 효과적인 캐스팅 방식은, ‘클래스 캐스팅을 사용할 경우 인터페이스를 선언하여 구현하고 인터페이스로 캐스팅하는 것’ 이다.

참고사항 : 개발자가 되는 법(http://wiki.kldp.org/wiki.php/HowToBeAProgrammer#s-2.1.4)

2.1.4 로그를 이용해서 디버그 하는 방법 

  로그 기록(logging)이란 정보를 제공하는 일련의 기록인 로그(log)를 생성하도록 시스템을 작성하는 활동을 말한다. 프린트 줄 넣기(printlining)는 간단한, 보통은 일시적인, 로그를 생성하기만 한다. 완전한 초보자들은 프로그래밍에 대해 아는 것에 한계가 있기 때문에 로그를 이해하고 사용해야 한다. 시스템 설계자들은 시스템의 복잡성 때문에 로그를 이해하고 사용해야 한다. 로그가 제공하는 정보의 양은, 이상적으로는 프로그램이 실행되는 중에도, 설정 가능해야 한다. 일반적으로 로그 기록은 다음의 이점이 있다.
  • 로그는 재현하기 힘든 (예를 들어, 개발 완료된 환경에서는 발생하지만 테스트 환경에서는 재현할 수 없는) 버그에 대한 유용한 정보를 제공할 수 있다.
  • 로그는, 예를 들어, 구문(statement)들 사이에 걸리는 시간과 같이, 성능에 관한 통계와 정보를 제공할 수 있다.
  • 설정이 가능할 때, 로그는 예기치 못한 특정 문제들을 디버그하기 위해, 그 문제들을 처리하도록 코드를 수정하여 다시 적용하지(redeploy) 않아도, 일반적인 정보를 갈무리할 수 있게 한다. 

  로그에 남기는 정보의 양항상 정보성과 간결성 사이의 타협으로 결정된다. 정보를 너무 많이 남긴다면 로그가 낭비적이 되고 스크롤에 가려지게(scroll blindness) 되어, 필요한 정보를 찾기 어려워질 것이다. 너무 조금 남긴다면 필요한 정보가 남지 않을 것이다. 이런 점에서, 무엇이 출력될지 설정할 수 있게 하는 것은 매우 유용하다. 일반적으로 로그에 남는 기록을 통해, 그 기록을 남긴 소스 코드의 위치, (적용 가능하다면) 문제가 되는 작업을 실행한 쓰레드, 정확한 실행 시각, 그리고 일반적으로, 어떤 변수의 값, 여유 메모리의 양, 데이터 객체의 개수 등 그 밖의 유용한 정보를 알 수 있다. 이러한 로그 생성 구문들은 소스 코드 전체에 흩어져 있는데, 특히 주요 기능이 있는 지점과 위험 부담이 있는 코드 근처에 있다. 구문마다 수준이 정해질 수 있으면 시스템의 현재 설정에 따라 그 수준에 해당하는 기록만 남기게 될 것이다. 로그 생성 구문을 설계할 때에는 어디에서 문제가 생길지 예상해서 그것을 기록으로 남길 수 있게 해야 한다. 성능을 측정할 필요성도 예상하고 있어야 한다.

영구적인 로그를 남긴다면, 로그 기록이 프린트 줄 넣기(printlining)를 대신 할 수 있을 것이고, 디버그 구문들 중에도 로그 기록 시스템에 영구적으로 추가할 것들이 있을 것이다.

로그(Logging) 과 관련된 글이 올라온 것을 보고,
급하게 내용을 찾아서 정리해본다.


  개발하는 과정에서 데이터의 처리 과정이나 발생한 오류에 대한 기록을 남기는 용도로 많이 활용하는 기능이다. 제대로 읽고 분석할 수 있는 능력을 갖춘다면, 개발실력이 한단계 향상될 것이라 믿어 의심치 않는다. 개발자가 갖춰야할 능력 중 하나는 '로그 분석' 능력!


+ Recent posts