[spring] AOP활용 logging

김영상 (dudtkd1221)·2023년 5월 9일

문득 동아리 홈페이지의 접속량이 궁금해졌습니다. 사실상 동아리 홈페이지를 접속할 이유가 시험기간에 족보보려고,,, 오는 목적이 90퍼센트 이상이라고 생각해서 시험기간전에 log data와 elk stack을 연동해서 시각화 형태로 모니터링하는게 목표였는데 계획에 차질이 생겨 일단은 로깅만 진행했습니다.

api endpoint,응답시간에 대한 로그정보 추출을 중점으로 진행했습니다.

logging 관련 의존성 추가

//logging
	implementation 'org.springframework.boot:spring-boot-starter-aop'
	implementation group: 'net.logstash.logback', name: 'logstash-logback-encoder', version: '6.3'

logback-spring.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/base.xml"/>
    <timestamp key="TIMESTAMP" datePattern="yyyyMMdd"/>

    <springProfile name="dev">
        <property name="LOG_PATH" value="/app/log"/>
    </springProfile>

    <springProfile name="prod">
        <property name="LOG_PATH" value="/app/log"/>
    </springProfile>

    <appender name="ELK" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
        <prudent>true</prudent>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_PATH}/sammaru-filebeat-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxFileSize>500MB</maxFileSize>
        </rollingPolicy>
    </appender>

    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
    </root>

    <logger name="ELK_LOGGER" level="INFO" additivity="false">
        <appender-ref ref="ELK"/>
    </logger>
</configuration>

통해 dev, prod 환경에서 LOG_PATH 지정해주었고요

RollingFileAppender
- FileAppender을 상속. 날짜와 용량등을 설정해서 패턴에 따라 로그가 각기 다른파일에 기록되게 할 수 있음.
%msg%
rollingPolicy :SizeAndTimeBasedRollingPolicy

설정 내용은 https://logback.qos.ch/manual/layouts.html 서 확인할 수 있습니다.

LogELK

@Getter
@Builder
public class LogELK {

    String timestamp;
    String clientIp;
    String clientUrl;
    String callFunction;
    String parameter;
    Double responseTime;

}

log정보를 담을 객체로 간단한게 필드로는 timestamp, clientIp, clientUrl, callFunction, parmeter, responseTime 를 담았습니다.

LogAspect

 
@Aspect
@Component
public class LogAspect {

    private static final String TIMESTAMP_FORMAT = "yyyy-MM-dd HH:mm:ss.SSS";
    private static final Logger log = LoggerFactory.getLogger("ELK_LOGGER");
    private ObjectMapper mapper = new ObjectMapper();
    private String clientIp = "";
    private String clientUrl = "";

    @Around("bean(*Controller)")
    public Object controllerAroundLogging(ProceedingJoinPoint pjp) throws Throwable {
        String timeStamp = new SimpleDateFormat(TIMESTAMP_FORMAT).format(new Timestamp(currentTimeMillis()));
        HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();

        this.clientIp = request.getRemoteAddr();
        this.clientUrl = request.getRequestURL().toString();

        String callFunction = pjp.getSignature().getDeclaringTypeName() + "." + pjp.getSignature().getName();

        StopWatch stopWatch = new StopWatch();
        stopWatch.start();

        Object result = pjp.proceed();

        stopWatch.stop();

        LogELK logelk = LogELK.builder()
                        .timestamp(timeStamp)
                        .clientIp(clientIp)
                        .clientUrl(clientUrl)
                        .callFunction(callFunction)
                        .parameter(mapper.writeValueAsString(request.getParameterMap()))
                        .responseTime(stopWatch.getTotalTimeSeconds()).build();

        log.info("{}", mapper.writeValueAsString(logelk));
        return result;
    }
}

LogAspect를 @Component로 등록합니다.

ControllingAroundLogging 메서드는 ProceedingJoinPoint 매개변수를 받으며, *Controller로 끝나는 빈의 메서드 호출을 가로채고 메서드 실행 주변에 사용자 정의 로직을 실행합니다.

빌더 패턴으로 timestamp, clientIp, clientUrl, callFunction, parmeter, responseTime으로 LogELK 클래스의 인스턴스를 생성했습니다.

log.info() 메서드에서 LogELK 인스턴스를 로깅하고, ObjectMapper를 사용하여 JSON 표현을 얻습니다.