[CICD] AOP, 로그백을 이용한 로그세팅하기
로그
에러발생시 원인분석, 에러발생시 알람보내기, 성능최적화를 위한 분석 등을 수행하기 위해 로그수집을 필수다. Spring Boot Application 은 기본적으로 CONSOLE 로그를 출력해준다. 지금까지는 CONSOLE 로그를 보면서 에러처리를 해왔다. 해당 방식은 첫번째 단점으로 CONSOLE 로그를 보면 눈이 아프다. 그리고 즉각적으로 필요한 정보를 찾기 힘들다. 두번째 단점으로 CONSOLE 로그는 서버가 내려가면 같이 사라진다. 그래서 파일로 저장해 둘 필요가 있었다.
AOP
AOP 는 관점지향 프로그래밍으로써 간단하게 말하면 비즈니스로직이 아닌 부가적인 목적으로 발생하는 로직을 분리하여 처리하는것을 말한다. 예를 들면 로깅, 트랜잭션, 권한등이 있다. 이런 부가기능을 Aspect 라는 별도의 모듈로 분리해서 처리한다.
나는 로깅에 이 AOP 를 적용해보았다. 예외가 터졌을 때와 프론트에서 Api 요청이 발생했을때 로그를 남긴다.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
@Slf4j
@Aspect
@Component
public class LogAspect {
@Pointcut("bean(*Service)")
private void allService() {
}
@Pointcut("bean(*Api)")
private void allRequest() {
}
@AfterThrowing(pointcut = "allService()", throwing = "ex")
private void logException(JoinPoint joinPoint, RuntimeException ex) {
String Name = ex.getClass().getSimpleName();
String Message = ex.getMessage();
String methodName = joinPoint.getSignature().toShortString();
Object[] args = joinPoint.getArgs();
log.warn("[Exception] {} Name=[{}] Message=[{}] args=[{}]",
methodName, Name, Message, args);
}
@Around("allRequest()")
private Object logRequest(ProceedingJoinPoint joinPoint) throws Throwable {
long beforeRequest = System.currentTimeMillis();
String methodName = joinPoint.getSignature().toShortString();
Object result = joinPoint.proceed();
long timeTaken = System.currentTimeMillis() - beforeRequest;
log.debug("[Request] {} time=[{}ms]", methodName, timeTaken);
return result;
}
}
Pointcut 의 경우 부가 기능을 어디에 적용할지 정한다. 메서드, 패키지, 클래스 다양하게 적용시킬 수 있으며 위 코드에서는 Service 이름으로 끝나는 빈과 Api 이름으로 끝나는 빈에 적용한다. logRequest 에서는 @Around 를 통해 메서드 호출전과 호출후에 실행한다. 그리고 호출전과 호출후에 시간을 측정해서 걸린 시간을 DEBUG 레벨로 로그를 남긴다. 해당 로그를 통해 개발자는 Api 에 요청에 걸린 시간을 확인하고 최적화를 수행할 수 있다. logException 에서는 @AfterThrowing 을 통해 예외를 던졌을때 실행되고, WARN 레벨로 로그를 남긴다.
Logback
AOP 를 통해 추가적으로 필요한 로그를 남겼다. 이제는 파일로 로그로 남길 차례다. 레벨별로 구분하여 파일로 로그를 남길려면 로그백을 사용해야 한다. 스프링이 로그백에 대해 로기 초기화를 제어하기위해서는 파일이름에 -spring 을 붙여줘야 된다. 그래서 resources 폴더 아래에 logback-spring.xml 을 추가해주었다.
logback-spring.xml
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
<configuration>
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
<property name="CUSTOM_CONSOLE_LOG_PATTERN" value="[%X{request_id:-dev}] ${CONSOLE_LOG_PATTERN}"/>
<property name="CUSTOM_FILE_LOG_PATTERN" value="[%X{request_id:-dev}] ${FILE_LOG_PATTERN}"/>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>${CUSTOM_CONSOLE_LOG_PATTERN}</pattern>
<charset>utf8</charset>
</encoder>
</appender>
<appender name="FILE-DEBUG" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>${CUSTOM_FILE_LOG_PATTERN}</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>DEBUG</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>logs/debug/debug-%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>1GB</totalSizeCap>
</rollingPolicy>
</appender>
<appender name="FILE-INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>${CUSTOM_FILE_LOG_PATTERN}</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>INFO</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>logs/info/info-%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>1GB</totalSizeCap>
</rollingPolicy>
</appender>
<appender name="FILE-WARN" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>${CUSTOM_FILE_LOG_PATTERN}</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>WARN</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>logs/warn/warn-%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>1GB</totalSizeCap>
</rollingPolicy>
</appender>
<appender name="FILE-ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>${CUSTOM_FILE_LOG_PATTERN}</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>logs/error/error-%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>1GB</totalSizeCap>
</rollingPolicy>
</appender>
<logger name="com.nainga.nainga" level="DEBUG" />
<root level="info">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="FILE-DEBUG"/>
<appender-ref ref="FILE-INFO"/>
<appender-ref ref="FILE-WARN"/>
<appender-ref ref="FILE-ERROR"/>
</root>
</configuration>
로그 레벨 별 파일 출력
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
<appender name="FILE-ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>${CUSTOM_FILE_LOG_PATTERN}</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>logs/error/error-%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>1GB</totalSizeCap>
</rollingPolicy>
</appender>
RollingFileAppender 를 이용하면 로그를 여러 파일에 나눠서 쓸 수 있다. LevelFilter 를 이용해 로그 레벨을 설정한다. 추후에 해당 로그 레벨을 선택해서 중요한 로그를 우선으로 볼 수 있다. <rollingPolicy> 태그에서는 파일이름, 최대저장기간과 최대사이즈를 지정할 수 있다. 파일이름은 날짜별로 저장해서 구분할 수 있게 하였다. 파일이 최대사이즈인 1GB 를 넘기면, 새롭게 로그파일을 생성한다. 그리고 30일이 지난 로그파일은 자동으로 삭제된다.
Root
1
2
3
4
5
6
7
8
<logger name="com.nainga.nainga" level="DEBUG" />
<root level="info">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="FILE-DEBUG"/>
<appender-ref ref="FILE-INFO"/>
<appender-ref ref="FILE-WARN"/>
<appender-ref ref="FILE-ERROR"/>
</root>
위에서 만든 <appender> 를 적용시킬려면 <root> 블록안에 넣어야 한다.
왜 root level = “info” 인가?
root level = "debug" 로 해야 debug 레벨 수준 로그부터 나온다. info 로 하면 debug 로그는 보이지 않는다. 그런데도 info 로 설정한 이유는 debug 로 설정하면 “라이브러리 디버그 로그” 까지 찍힌다. 해당 로그량이 매우 엄청나다. 몇시간도 안돼서 1GB 로그를 돌파했었다. 이걸 모르고 하루나뒀더니 디스크 용량이 가득 차서 서버가 터졌었다. 이런 라이브러리 디버그 로그는 불필요한 정보이기에 저장하지 않도록 했다.
하지만 필요한 debug 로그
라이브러리 디버그 로그는 필요없지만, 내 프로젝트에 관한 디버그 로그는 필요하다. 그래서 AOP 에서 설정했던 debug 로그가 나올거 아닌가
1
<logger name="com.nainga.nainga" level="DEBUG" />
그래서 위 코드를 통해 지정된 패키지(내 프로젝트 패키지) 에 대한 debug 로그는 출력되도록 설정한다.
.gitignore
Logback 을 통해 로그를 남겼다면 실제로 파일이 생길것이다. 당연히 해당 파일은 github 에 불필요한 파일이니 .gitignore 에 등록해서 github 에 안올라가도록 설정해야한다. .gitignore 에 아래처럼 폴더를 설정해두자.
### 로그 파일 ###
/logs
마무리
AOP 로 원하는 로그를 남기고 로그백을 통해 관리하였다. 이제 로그를 파일로 남겼으니, 이제 시각화를 통해 좀 더 보기 편하게 바꿀려고 한다.