Spring AOP 스프링이 해줄건데 너가 왜 어려워 해? Spring boot에서 aop logging 사용법 제일 쉽게 알려드립니다!

Spring AOP (Aspect Oriented Programming)

- AOP는 관점 지향 프로그래밍으로 "기능을 핵심 비즈니스 기능과 공통 기능으로 '구분'하고, 공통 기능을 개발자의 코드 밖에서 필요한 시점에 적용하는 프로그래밍 방법"이다.

위의 한 줄만 기억하면 된다.

초보에게 Aspect, Advice, Pointcut, Weaving, Joinpoint, ... 이런거는 AOP를 이해하는데 방해하는 요소일 뿐이다. 

추후에 AOP에 대해서 활용하고 싶고 깊이있게 이해하고 싶을 때 위에 나열한 것들에 대해서 공부해본다.

---

스프링부트에서 초간단 AOP 적용하는 법 3단계

1. spring-boot-starter-aop dependency 적용하기

라이브러리는 있어야지.

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId>
</dependency>

2. @EnableAspectJAutoProxy 적용하기

최상위 패키지에 있는 클래스에 Annotation을 적용해서 AOP를 찾을 수 있게 해준다.

@EnableAspectJAutoProxy
@SpringBootApplication
public class AoploggingApplication {
 
    public static void main(String[] args) {
        SpringApplication.run(AoploggingApplication.class, args);
    }
}

3. 공통기능을 정의하고 공통기능이 사용될 시점을 정의한다.

@Aspect
@Component
public class LogAspect {
    Logger logger =  LoggerFactory.getLogger(LogAspect.class);
    
    //BookService의 모든 메서드
    @Around("execution(* com.example.demo.service.BookService.*(..))")
    public Object logging(ProceedingJoinPoint pjp) throws Throwable {
        logger.info("start - " + pjp.getSignature().getDeclaringTypeName() + " / " + pjp.getSignature().getName());
        Object result = pjp.proceed();
        logger.info("finished - " + pjp.getSignature().getDeclaringTypeName() + " / " + pjp.getSignature().getName());
        return result;
    }
}

끝.

무슨말인지 이해하기 어렵다. 아래에서 예제와 함께 설명을 보고 이해해보도록 한다.

---

AOP 예제와 부연 설명 

이론적인것에 대해서는 잘 모르겠고 위의 3단계가 베이스이자 전부다.

라이브러리를 불러오는 건 당연하고, @EnableAspectJAutoProxy는 스프링이 자동으로 개발자의 메서드를 호출하기 전에 가로챌 수 있게 하는 옵션이라고 보면된다.

이렇게 가로채야만 메서드를 사용하기 전이든 사용 후든 둘다든 어떤 시점에 적용할 수 있다.

예제를 설명하기 앞서 위에서 강조했던 문장을 다시 한 번 되새긴다.

AOP는 관점 지향 프로그래밍으로 "기능을 핵심 비즈니스 기능과 공통 기능으로 '구분'하고, 공통 기능을 개발자의 코드 밖에서 필요한 시점에 적용하는 프로그래밍 방법"이다.

> 패키지 구조

핵심 비즈니스 기능과 공통 기능으로 구분해야 한다고 했다.

평소에 작성하던 프로젝트에는 보통 MVC구조로 작성되어 있을 것이고 해당 코드는 핵심 비즈니스 로직일 것이다.

따로 aop 패키지로 빠져있는 것이 여기서는 공통 로직이다. (분리되었음.)

기존에 작성한 핵심 비즈니스 로직에는 AOP 때문에 단 한글자도 코드가 변경된 것이 있어서는 안된다.

> AoploggingApplication.java

package com.example.demo;
 
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.annotation.EnableAspectJAutoProxy;
 
@EnableAspectJAutoProxy
@SpringBootApplication
public class AoploggingApplication {
 
    public static void main(String[] args) {
        SpringApplication.run(AoploggingApplication.class, args);
    }
}
 

> MyController.java

package com.example.demo.controller;
 
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
 
import com.example.demo.service.BookService;
import com.example.demo.service.HelloService;
 
@RestController
public class MyController {
    @Autowired
    private BookService bookService;
    @Autowired
    private HelloService helloService;
    
    @GetMapping("/")
    public String index() {
        bookService.findBookByTitle("spring");
        return "indexPage";
    }
    @GetMapping("/hello")
    public String hello() {
        helloService.hello();
        return "hello";
    }
}

> Book.java (dto)

package com.example.demo.dto;
 
public class Book {
    private String title;
    private String isbn;
    private int price;
    
    public String getTitle() {
        return title;
    }
    public void setTitle(String title) {
        this.title = title;
    }
    public String getIsbn() {
        return isbn;
    }
    public void setIsbn(String isbn) {
        this.isbn = isbn;
    }
    public int getPrice() {
        return price;
    }
    public void setPrice(int price) {
        this.price = price;
    }    
    public Book(String title, String isbn, int price) {
        super();
        this.title = title;
        this.isbn = isbn;
        this.price = price;
    }
    @Override
    public String toString() {
        return "Book [title=" + title + ", isbn=" + isbn + ", price=" + price + "]";
    }
}
 

> BookService.java

package com.example.demo.service;
 
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Service;
 
import com.example.demo.repository.BookDao;
 
 
@Service
public class BookService {
    
    @Autowired
    private BookDao bookDao;
    
    public void findBookByTitle(String title) {
        System.out.println(bookDao.findBookByTitle(title));
    }
}

> HelloService.java

package com.example.demo.service;
 
import org.springframework.stereotype.Service;
 
@Service
public class HelloService {
    
    public void hello() {
        System.out.println("hello world!");
    }
}

> BookDao.java

package com.example.demo.repository;
 
import java.util.ArrayList;
import java.util.List;
 
import javax.annotation.PostConstruct;
 
import org.springframework.stereotype.Repository;
 
import com.example.demo.dto.Book;
 
@Repository
public class BookDao {
    
    private List<Book> books;
    
    @PostConstruct
    private void init() {
        books = new ArrayList<>();
        Book book1 = new Book("spring","1488526510",30000);
        Book book2 = new Book("spring boot","1488751510",35000);
        Book book3 = new Book("boot spring boot","1481124536",25000);
        books.add(book1);
        books.add(book2);
        books.add(book3);
    }
    
    public Book findBookByTitle(String title) {
        return books.stream().filter(book->book.getTitle().equals(title)).findFirst().orElse(new Book("","",0));
    }
}

> LogAspect.java

package com.example.demo.aop;
 
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
 
@Aspect
@Component
public class LogAspect {
    Logger logger =  LoggerFactory.getLogger(LogAspect.class);
    
    //BookService의 모든 메서드
    @Around("execution(* com.example.demo.service.BookService.*(..))")
    /*@Around("execution(* com.example.demo.controller..*.*(..))")*/
    /*@Around("execution(* com.example.demo..*.*(..))")*/
    public Object logging(ProceedingJoinPoint pjp) throws Throwable {
        logger.info("start - " + pjp.getSignature().getDeclaringTypeName() + " / " + pjp.getSignature().getName());
        Object result = pjp.proceed();
        logger.info("finished - " + pjp.getSignature().getDeclaringTypeName() + " / " + pjp.getSignature().getName());
        return result;
    }
}

소스 코드 전체를 공개해서 꽤나 긴데 내용은 단순하다.

MVC를 위해서 Controller, Service, Dto, Dao등 구색만 갖췄고 Dao는 DB연결 없이 임의의 Book객체 3개를 넣어놓았다.

LogAspect.java 를 제외하고는 일반적인 예제, 사용 프로젝트 구성과 유사하다.

LogAspect가 이제 핵심 비즈니스 로직과 분리된 공통 로직인 것을 확인할 수 있고, 예제에서는 메서드를 실행하기 전/후로 로그를 찍어서 디버깅하기 좋은 코드를 만들었다.

@Aspect, @Componet로 이 클래스가 AOP가 바라보는 관점을 정의하고 bean으로 등록하는 것을 정의했다.

@Around는 메서드의 실행 전/후에 공통로직을 적용하고 싶을 때 사용하고 @Before는 메서드 실행 전에, @After는 메서드 실행 후에 공통 로직을 적용하고 싶을 때 사용한다.

즉 어느 시점에 적용할 것인지를 정의하는 것이다.

@Around("execution(* com.example.demo.service.BookService.*(..))") 를 통해서 어떤 메서드들이 이 AOP를 적용받을 것인지를 정의했다.

execution(* com.example.demo.service.BookService.*(..))는 com.example.demo.service 패키지의 BookService의 모든 메서드가 적용받을 것이라고 한 것이다. (pointcut 표현식)

다양한 표현식을 이용해서 원하는 부분에만 적용할 수 있을 것이다.

다른 블로그에서 인용(?)해온 표현식들을 보고 알맞게 적용할 수 있도록 하자.

Pointcut	JoinPoints
execution(public * *(..))	public 메소드 실행
execution(* set*(..))	이름이 set으로 시작하는 모든 메소드명 실행
execution(* get*(..))	이름이 get으로 시작하는 모든 메소드명 실행
execution(* com.xyz.service.AccountService.*(..))	AccountService 인터페이스의 모든 메소드 실행
execution(* com.xyz.service.*.*(..))	service 패키지의 모든 메소드 실행
execution(* com.xyz.service..*.*(..))	service 패키지와 하위 패키지의 모든 메소드 실행
within(com.xyz.service.*)	service 패키지 내의 모든 결합점 (클래스 포함)
within(com.xyz.service..*)	service 패키지 및 하위 패키지의 모든 결합점 (클래스 포함)
bean(*Repository)	이름이 “Repository”로 끝나는 모든 빈
bean(*)	모든 빈
bean(account*)	이름이 'account'로 시작되는 모든 빈
bean(*dataSource) || bean(*DataSource)	이름이 “dataSource” 나 “DataSource” 으로 끝나는 모든 빈

출처 : http://devjms.tistory.com/70

공통으로 사용될 메서드를 보도록 하자.

여기서는 Object를 리턴하도록 되어있는데 아주 중요하다.

왜냐하면 AOP는 메서드를 가로채서(Proxy) 앞이나 뒤에 필요한 공통로직을 한다고 했기 때문이다.

즉 proceed()에서 정상적으로 메서드를 실행한 후 리턴 값을 주는데 가로채서 어떤 action을 한 후에 기존 리턴 값을 되돌려 주지 않으면 가로챈 AOP가 결과값을 변경한 것, 지워버린 것과 다름없다.

위 메서드에서는 단순하게 앞/뒤로 추가 로깅을 찍어주고 기존 메서드가 실행될 수 있게 pjp.proceed();를 호출했다.

설명하기 어려운데 결과를 보면 조금 더 이해할 수 있다.

2018-11-23 12:09:16.834  INFO 11348 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2018-11-23 12:09:16.834  INFO 11348 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2018-11-23 12:09:16.839  INFO 11348 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 5 ms
2018-11-23 12:09:16.840  INFO 11348 --- [nio-8080-exec-1] com.example.demo.aop.LogAspect           : start - com.example.demo.service.BookService / findBookByTitle
Book [title=spring, isbn=1488526510, price=30000]
2018-11-23 12:09:16.844  INFO 11348 --- [nio-8080-exec-1] com.example.demo.aop.LogAspect           : finished - com.example.demo.service.BookService / findBookByTitle

localhost:8080/으로 접속했을 때 @Around("execution(* com.example.demo.service.BookService.*(..))")의 로그다.

BookService의 모든 메서드에서만 aop가 적용되므로 helloService의 메서드에는 적용이 되지 않는다.

2018-11-23 12:12:46.124  INFO 11348 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2018-11-23 12:12:46.124  INFO 11348 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2018-11-23 12:12:46.133  INFO 11348 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 9 ms
2018-11-23 12:12:46.134  INFO 11348 --- [nio-8080-exec-1] com.example.demo.aop.LogAspect           : start - com.example.demo.controller.MyController / index
Book [title=spring, isbn=1488526510, price=30000]
2018-11-23 12:12:46.139  INFO 11348 --- [nio-8080-exec-1] com.example.demo.aop.LogAspect           : finished - com.example.demo.controller.MyController / index

이번에는 @Around("execution(* com.example.demo.controller..*.*(..))")의 로그다.

controller 하위 패키지까지의 모든 메서드가 aop에 적용된다. service는 controller패키지 하위에 있는 패키지가 아니므로 찍히지 않는 것을 볼 수 있다.

2018-11-23 12:15:47.981  INFO 11348 --- [nio-8080-exec-3] com.example.demo.aop.LogAspect           : start - com.example.demo.controller.MyController / index
2018-11-23 12:15:47.981  INFO 11348 --- [nio-8080-exec-3] com.example.demo.aop.LogAspect           : start - com.example.demo.service.BookService / findBookByTitle
2018-11-23 12:15:47.984  INFO 11348 --- [nio-8080-exec-3] com.example.demo.aop.LogAspect           : start - com.example.demo.repository.BookDao / findBookByTitle
2018-11-23 12:15:47.988  INFO 11348 --- [nio-8080-exec-3] com.example.demo.aop.LogAspect           : finished - com.example.demo.repository.BookDao / findBookByTitle
Book [title=spring, isbn=1488526510, price=30000]
2018-11-23 12:15:47.988  INFO 11348 --- [nio-8080-exec-3] com.example.demo.aop.LogAspect           : finished - com.example.demo.service.BookService / findBookByTitle
2018-11-23 12:15:47.988  INFO 11348 --- [nio-8080-exec-3] com.example.demo.aop.LogAspect           : finished - com.example.demo.controller.MyController / index

이번에는 @Around("execution(* com.example.demo..*.*(..))")의 로그다. demo패키지 이하의 하위패키지들도 포함되는 모든 메서드에 aop를 적용한 것이다.

로그에서 보는 것과 같이 타고 들어가는 순서 전체가 나온다.

Dao가 완전히 실행을 마친 후에 Book정보가 나오는 이유는 BookService에서 print하기 때문이다...