Spring AOP, Logging이 필요한 시점

• AOP : Aspected Oriented Programming
• 관점 지향 프로그래밍
• oop의 하위 개념

---

(ex) 어느 한 함수 처리에 걸리는 시간 측정 want

• 실제 서비스 흐름과는 별개
  • 로그 남기는 기능
  • 서비스 제공 위한 기능
• 이는 서비스 흐름과 직접 연관없어서 기능과는 별도로 작성하는 것이 이상적

---

• Aspect : 서로 다른 역할의 객체들이 가지는 공통의 관심사

  • Aspect Oriented Programming
    : 서로 다른 비즈니스 로직이 공통으로 가지는 관심에 대해 고민하는 개발 지향 (아래 이미지 참고)

(+) 1. 설명 참고

• 서비스들의 비즈니스 메소드들은 복잡한 코드로 구성되어있는데, 그 중 핵심 로직은 얼마안되고 대부분은 트랜잭션, 로깅 처리, 인증과 관련된 코드들이 있을 수 있음
• => 이럴 때 비핵심이지만 꼭 필요하고, 공통화할 수 있는 부분을 따로 빼서(횡단 분리) 관리

• 조인포인트(Joinpoint) : 클라이언트가 호출하는 모든 비즈니스 메소드, 조인포인트 중에서 포인트컷되기 때문에 포인트컷의 후보로 생각할 수 있다.
• 포인트컷(Pointcut) : 특정 조건에 의해 필터링된 조인포인트, 수많은 조인포인트 중에 특정 메소드에서만 횡단 공통기능을 수행시키기 위해서 사용한다.
• 표현식 : 리턴타입 패키지경로 클래스명 메소드명(매개변수)
• 어드바이스(Advice) : 횡단 관심에 해당하는 공통 기능의 코드, 독립된 클래스의 메소드로 작성한다.
  어드바이스의 동작 시점

  Before : 메소드 실행 전에 동작
  After: 메소드 실행 후에 동작
  After-returning: 메소드가 정상적으로 실행된 후에 동작
  After-throwing: 예외가 발생한 후에 동작
  Around: 메소드 호출 이전, 이후, 예외발생 등 모든 시점에서 동작

• 위빙(Weaving) : 포인트컷으로 지정한 핵심 관심 메소드가 호출될 때, 어드바이스에 해당하는 횡단 관심 메소드가 삽입되는 과정을 의미한다. 이를 통해 비즈니스 메소드를 수정하지 않고도 횡단 관심에 해당하는 기능을 추가하거나 변경이 가능해진다.
• 애스팩트(Aspect) : 포인트컷과 어드바이스의 결합,
  어떤 포인트컷 메소드에 대해 어떤 어드바이스 메소드를 실행할지 결정

(+) 2. 설명 참고
1. Advice

언제 공통 관심 기능을 핵심 로직에 적용할 지를 정의하고 있다. 예를 들어, '메서드를 호출하기 전'(언제)에 '트랜잭션을 시작한다.'(공통기능)기능을 적용한다는 것을 정의하고 있다.

Target 클래스에 조인 포인트에 삽입되어져 동작(적용할 기능)할 수 있는 코드를 '어드바이스'라 한다.

관점으로서 분리되고 실행시 모듈에 위빙된 구체적인 처리를 AOP에서는 Advice라고 한다. Advice를 어디에서 위빙하는지는 뒤에 나오는 PointCut이라는 단위로 정의한다.

또한 Advice가 위빙되는 인스턴스를 '대상객체'라고 한다.

advice는 Pointcut에서 지정한 Jointpoint에서 실행되어야하는 코드이다.

cp.) 스프링의 Advice 타입

• Around Advice: Joinpoint 앞과 뒤에서 실행되는 Adcvice

• Before Advice: Joinpoint 앞에서 실행되는 Advice

• After Returning Advice: Jointpoint 메서드 호출이 정상적으로 종료된 뒤에 실행되는 Advice

• After Throwing Advice: 예외가 던져질 때 실행되는 Advice

• Introduction: 클래스에 인터페이스와 구현을 추가하는 특수한 Advice

2. JoinPoint

Advice를 적용 가능한 지점을 의미한다. 메서드 호출, 필드 값 변경 등이 Joinpoint에 해당한다.

클래스의 인스턴스 생성 시점', '메소드 호출 시점', '예외 발생 시점'과 같이 어플리케이션을 실행할 때 특정 작업이 시작되는 시점을 '조인포인트'라고 한다

실행시의 처리 플로우에서 Advice를 위빙하는 포인트를 JointPoint라고 한다. 구체적으로는 메서드 호출이나 예외발생이라는 포인트를 Joinpoint라고 한다.

인스턴의 생성시점, 메소드를 호출하는 시점, Exception이 발생하는 시점과 같이 어플리케이션이 실행될 때 특정작업이 실행되는 시점을 의미한다.

3. Pointcut

Joinpoint의 부분 집합으로서 실제로 Advice가 적용되는 Jointpoint를 나타낸다. 스프링에서는 정규 표현식이나 AspectJ 문법을 이용하여 Pointcut을 정의할 수 있다.

여러 개의 조인포인트를 하나로 결합한 것을 포인트 컷이라 한다.

하나 또는 복수의 Jointpoint를 하나로 묶은 것을 Pointcut 이라고 한다. Advice의 위빙 정의는 Pointcut을 대상으로 설정한다. 하나의 Pointcut에는 복수 Advice를 연결할 수 있다. 반대로 하나의 Advice를 복수 Pointcut에 연결하는 것도 가능하다.

Pointcut(교차점)은 JoinPoint(결합점)들을 선택하고 결합점의 환경정보를 수집하는 프로그램의 구조물이다. Target 클래스와 Advice가 결합(Weaving)될 때 둘 사이의 결합 규칙을 정의하는 것이다.

4. Weaving
Advice를 핵심 로직 코드에 적용하는 것을 weaving 이라고 한다.(분리한 관점을 여러 차례 모률에 삽입하는 것을 AOP에서는 위빙 (Weaving: 엮기)이라고 부른다.) 즉 공통 코드를 핵심 로직 코드에 삽입하는 것이 weaving이다.
어드바이스를 핵심 로직 코드에 삽입하는 것을 위빙이라고 한다.
Aspect를 target 객체에 제공하여 새로운 프록시 객체를 생성하는 과정을 말한다.

5. Aspect
여러 객체에 공통으로 적용되는 공통 관심 사항
트랜잭션이나 보안 등이 Aspect의 좋은 예이다.
여러 객체에 공통으로 적용되는 공통 관점 사항을 에스펙트
Aspect는 AOP의 중심단위, Advice와 Pointcut을 합친 것이다.(Advisor)

6.Target
핵심 로직을 구현하는 클래스를 말한다.
충고를 받는 클래스를 대상(target)
대상은 여러분이 작성한 클래스는 물론, 별도의 기능을 추가하고자 하는 써드파티 클래스가 될 수 있다.

7. advisor
어드바이스와 포인트컷을 하나로 묶어 취급한 것을 '어드바이저'라 부른다.
advisor와 Pointcut을 하나로 묶어 다루는 것을 Advisor라고 한다. Advisor는 스프링 AOP에만 있는 것인데, 관점 지향에서 관점을 나타내는 개념이라고 할 수 있다.

8. proxy
대상 객체에 Advice가 적용된 후 생성된 객체

---

실제로 적용해보기

1) aspect라는 패키지 만들기
2) 해당 패키지 안에 annotation으로 LogExecutionTime 만들기

@Target(ElementType.METHOD)
//타켓 어노 : 아래 아이가 어디에 붙을 수 있는지 지정해주는 것
//즉 얘는 함수에 붙기 위한 아이라고 알려주는 것
@Retention(RetentionPolicy.RUNTIME)
// retention : 어느 시점까지 존재할 것인지 
//(옵션 source:그저표기용 class runtime)
// aop 구현할 때는 런타임 중에 어노테이션이 어딨는지 알아야해서 
//runtime으로 해주기
	public @interface LogExecutionTime {
}

3) aop의 경우 gradle에서 의존성 추가해야 함

	implementation 'org.springframework.boot:spring-boot-starter-app'

• 이렇게 설정한 annotation 들 따라서 구현될 aspect들을 만들어보자

4) LoggingAspect 클래스 aspect 패키지 안에 추가

@Aspect//이 클래스가 관점임 알려줌
@Component
public class LoggingAspect {
    private static final Logger logger = LoggerFactory.getLogger(LoggingAspect.class);

    // 아래는 advice로써 작용할 함수다
    // 또한 어떤 joinpoint에 들어갈 지 정해주는 pointcut 필요 -> annotation으로 붙여주자
    @Around(value="@annotation(LogExecutionTime)") //이 어노테이션 주변 애들에서 얘가 작동
    //어떤 특정 포인트 기준으로 주변에서 작동하는 아이임 알려주기
//around 외에도 다양한 시간적정의 존재
    //조인포인트 : 관점이 시행될 한 지점
    //프로시딩 조인포인트 : 일반적인 조인포인트랑 다름
    public Object logExecuitonTime(ProceedingJoinPoint joinPoint) throws Throwable{
        long startTime= System.currentTimeMillis();
        Object proceed = joinPoint.proceed(); //조인포인트 객체 선언
        long execTime = System.currentTimeMillis()-startTime;
        logger.trace("method executed in{}", execTime);
        return proceed;
    }
}

(+) proceed 설명 - 출처 블로그

• around 어드바이스의 경우는 클라이언트 호출을 가로챈다. 만일 around 어드바이스 메소드에서 바로 return을 해 버리면 비지니스 메소드 자체가 실행이 안된다.

• 따라서 around Advice 메소드에서 비지니스 메소드 호출에 대한 책임을 감당해야 한다. - 즉 around Advice가 비지니스 호출을 가로챘기 때문에 around Advice에서 비지니스 호출을 해 주지 않으면 비지니스 메소드는 실행 될 길이 없다.

• 그런데 그렇게 할려면 비지니스 메소드에 대한 정보를 around Advice 메소드가 가지고 있어야 하는데 그 정보를 Srping 컨테이너가 around Advice 메소드로 넘겨준다. 그게 ProceedingJoinPoint 객체이다.

• around Advice 메소드는 다음과 같은 형태를 띤다. 여기서 비지니스 메소드로 진행하도록(proceed) 하는 메소드가 proceed() 메소드이다.

• 이 메소드를 실행하기 전에 비지니스 메소드 호출 전에 처리할 코드를 수행하도록 하면 된다.

• proceed()를 기준으로 비지니스 메소드 수행 전과 후가 나뉘어 진다. 즉 proceed()가 호출 되기 전에는 비지니스 메소드 호출 전이고 proceed()가 호출된 후에는 비지니스 메소드 호출 후라고 생각하면 된다.
  Object org.aspectj.lang.ProceedingJoinPoint.proceed() throws Throwable

• 그런데 여기서 proceed() 메소드가 반환하는 값이 있는데 Object이다. 여기에 무엇이 담겨 있단 말인가?

• 여기에는 비지니스 메소드가 실행한 후의 결과 값들이 담겨 있게 된다.

• 예를 들어 비지니스 메소드의 기능이 select 기능이라고 한다면 그 결과 값(보통은 VO 형태에 담기고 이 VO가 Object에 담기게 된다)이 Object에 담기게 되고 insert와 같이 return 되는 값이 없을 경우에는 Object에는 null이 담기게 된다.

5) Controller에 LogExecutiontime 어노테이션 붙여주기

    @LogExecutionTime
    @GetMapping("")
    public List<PostDto > readPostAll(){
        return this.postservice.readPostAll();
    }

6) logback-spring 수정

    <logger name="jsbdy.jpa.aspect" level="trace" additivity="false">
        <appender-ref ref="RollingFile" />
        <appender-ref ref="Console" />
    </logger>

• aspect 패키지 내부에 있는 것만 trace log 붙이는 것으로

7) 시간 찍히나 확인해보기

• controller 중 get-all 메소드에 어노테이션 붙였으니깐 해당 메소드를 실행할 때 (포스트맨) 우리가 작성한 aspect가 잘 실행돼서 로그가 남나.. 확인해보장
  => 잘 남는다

---

추가 작업

8) LogParameters 어노테이션 또 생성

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
	public @interface LogParameters {
}

9) Aspect에 코드 추가 (아깐 around 이번엔 before로)

    @Before(value="@annotation(LogParameters)")
    //특정 시점 이전에 뭐가 일어났는지 알려주는 거라서 따로 반환해줄 객체 음슴- void로~
    public void logParameter(JoinPoint joinPoint){
        MethodSignature methodSignature=(MethodSignature) joinPoint.getSignature();
        //함수가 어떤 모양 가지는지 알려주는 메소드 시그니처
        logger.trace("method description:[{}]",methodSignature.getMethod());
        logger.trace("method name: [{}]", methodSignature.getName());
        logger.trace("declaring class: [{}]", methodSignature.getDeclaringType());
        //어노테이션 이름에있는 파라미터 받아오기
        //조인포인트 시행 전 데려옴
        //얘에 있는 parameter을 우리가 가지고 싶은 것
        Object[] arguments = joinPoint.getArgs();
        if (arguments.length==0){
            logger.trace("no arguments");
        }
        for (Object argument:arguments){
            logger.trace("argument [{}]", argument);
        }
    }

(10) Controller에 또 붙이기

    @LogParameters
    @PostMapping()
    @ResponseStatus(HttpStatus.CREATED)
    public void createPost(

(11) 결과 로그

아래로 post

{
    "title":"1 spring CRUD",
    "content":"test posting",
    "writer":"shucream"
}

log

2022-03-04 22:53:39,075 TRACE [http-nio-8080-exec-2] LoggingAspect: method description:[public void jsbdy.jpa.PostController.createPost(jsbdy.jpa.PostDto)]
2022-03-04 22:53:39,082 TRACE [http-nio-8080-exec-2] LoggingAspect: method name: [createPost]
2022-03-04 22:53:39,083 TRACE [http-nio-8080-exec-2] LoggingAspect: declaring class: [class jsbdy.jpa.PostController]
2022-03-04 22:53:39,084 TRACE [http-nio-8080-exec-2] LoggingAspect: argument [PostDto{id=0, title='1 spring CRUD', content='test posting', writer='shucream', boardId=0}]

(12) 이름 refactor, param -> argument

(13) around,before 받고 이제 afterreturning 구현~
~~@afterreturning

(14) 이를 위한 annotation LogReturn 생성

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface LogReturn {
}

(15) AfterReturning 코드 구현

    @AfterReturning(value="@annotation(LogReturn)",returning ="returnValue")
    //반환값이 존재하는 애가 리턴한 후에
    //반환값을 logResults의 인자로 넘겨줘야 함
    //returning에서 정의된이름을 가진 애한테 (지금은 아랫줄아이) 반환값 대입시킴
    public void logResults(JoinPoint joinPoint, Object returnValue){
        MethodSignature  methodSignature=(MethodSignature) joinPoint.getSignature();
        logger.trace("method name : [{}]", methodSignature.getName());
        logger.trace("return type : [{}]", methodSignature.getDeclaringTypeName());
        logger.trace("return value: [{}]", methodSignature, returnValue);
    }

(16) controller에 적합한데 붙여버리기

    @LogReturn
    @GetMapping("{id}")
    public PostDto readPost(
            @PathVariable("id")int id
    ){
       return this.postservice.readPost(id);
    }

(17) 로그 결과 확인

2022-03-04 23:11:33,827 TRACE [http-nio-8080-exec-4] LoggingAspect: method description:[public void jsbdy.jpa.PostController.createPost(jsbdy.jpa.PostDto)]
2022-03-04 23:11:33,830 TRACE [http-nio-8080-exec-4] LoggingAspect: method name: [createPost]
2022-03-04 23:11:33,830 TRACE [http-nio-8080-exec-4] LoggingAspect: declaring class: [class jsbdy.jpa.PostController]
2022-03-04 23:11:33,853 TRACE [http-nio-8080-exec-4] LoggingAspect: argument [PostDto{id=0, title='1 spring CRUD', content='test posting', writer='shucream', boardId=0}]
2022-03-04 23:11:37,528 TRACE [http-nio-8080-exec-5] LoggingAspect: method name : [readPost]
2022-03-04 23:11:37,529 TRACE [http-nio-8080-exec-5] LoggingAspect: return type : [jsbdy.jpa.PostController]
2022-03-04 23:11:37,530 TRACE [http-nio-8080-exec-5] LoggingAspect: return value: [PostDto jsbdy.jpa.PostController.readPost(int)]