Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat(log): add logging filter & AOP module #94

Merged
merged 16 commits into from
Aug 14, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
42 changes: 42 additions & 0 deletions src/main/java/com/e2i/wemeet/config/log/LogConfig.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,42 @@
package com.e2i.wemeet.config.log;

import com.e2i.wemeet.config.log.aspect.ControllerLogAspect;
import com.e2i.wemeet.config.log.aspect.QueryCounterAspect;
import com.e2i.wemeet.config.log.aspect.ServiceLogAspect;
import com.e2i.wemeet.config.log.module.QueryCounter;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.util.StopWatch;
import org.springframework.web.context.annotation.RequestScope;

@Configuration
public class LogConfig {

@RequestScope
@Bean
public StopWatch apiWatch() {
return new StopWatch();
}

@RequestScope
@Bean
public QueryCounter queryCounter() {
return new QueryCounter();
}

@Bean
public QueryCounterAspect queryCounterAspect() {
return new QueryCounterAspect(queryCounter());
}

@Bean
public ControllerLogAspect logControllerAspect() {
return new ControllerLogAspect();
}

@Bean
public ServiceLogAspect logServiceAspect() {
return new ServiceLogAspect();
}

}
129 changes: 129 additions & 0 deletions src/main/java/com/e2i/wemeet/config/log/LogFilter.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,129 @@
package com.e2i.wemeet.config.log;

import static com.e2i.wemeet.config.log.MdcKey.CORRELATION_ID;
import static com.e2i.wemeet.config.log.MdcKey.MEMBER_ID;

import com.e2i.wemeet.config.log.module.QueryCounter;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.UUID;
import lombok.extern.slf4j.Slf4j;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;
import org.springframework.util.StringUtils;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.ContentCachingResponseWrapper;

@Slf4j
@Component
public class LogFilter extends OncePerRequestFilter {

private static final String REQUEST_LOG_FORMAT = "REQUEST:: HTTP_METHOD: {}, URL: {}, AGENT: {}, BODY: {}";
private static final String RESPONSE_LOG_FORMAT = "RESPONSE:: HTTP_METHOD= {}, URL= {}, STATUS_CODE= {}, QUERY_COUNT= {}, TIME_TAKEN= {}ms, MEMBER_ID= {}, BODY= {}";
private static final String QUERY_COUNT_WARNING_LOG_FORMAT = "WARN QUERY EXECUTION TIME:: {}";

private static final int QUERY_COUNT_WARNING_STANDARD = 10;
private static final String NO_REQUEST_BODY = "none";
private static final String NOT_AUTHENTICATED = "none";

private final StopWatch apiWatch;
private final QueryCounter queryCounter;

public LogFilter(final StopWatch apiWatch, final QueryCounter queryCounter) {
this.apiWatch = apiWatch;
this.queryCounter = queryCounter;
}

@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
throws ServletException, IOException {
final ContentCachingRequestWrapper requestWrapper = new ContentCachingRequestWrapper(request);
final ContentCachingResponseWrapper responseWrapper = new ContentCachingResponseWrapper(response);

// Before request
addCorrelationIdToMdc();

apiWatch.start();
filterChain.doFilter(requestWrapper, responseWrapper);
apiWatch.stop();

// After request
loggingRequest(requestWrapper);
loggingResponse(requestWrapper, responseWrapper);
notifyQueryCountWarning();

MDC.clear();
responseWrapper.copyBodyToResponse();
}

// 쿼리 수행 개수가 QUERY_COUNT_WARNING_STANDARD 이상일 경우, 로그를 남긴다.
private void notifyQueryCountWarning() {
if (getQueryCount() >= QUERY_COUNT_WARNING_STANDARD) {
log.warn(QUERY_COUNT_WARNING_LOG_FORMAT, getQueryCount());
}
}

// Request Logging
private void loggingRequest(final ContentCachingRequestWrapper requestWrapper) {
final String method = requestWrapper.getMethod();
final String url = getUrlWithQueryParameters(requestWrapper);
final String agent = requestWrapper.getHeader("User-Agent");
final String body = new String(requestWrapper.getContentAsByteArray());

if (!StringUtils.hasText(body)) {
log.info(REQUEST_LOG_FORMAT, method, url, agent, NO_REQUEST_BODY);
return;
}

log.info(REQUEST_LOG_FORMAT, method, url, agent, body);
}

// Response Logging
private void loggingResponse(final ContentCachingRequestWrapper requestWrapper,
final ContentCachingResponseWrapper responseWrapper) {
final String method = requestWrapper.getMethod();
final String url = getUrlWithQueryParameters(requestWrapper);
final int statusCode = responseWrapper.getStatus();

final int queryCount = getQueryCount();
final long timeTaken = apiWatch.getTotalTimeMillis();
final String memberId = getMemberId();
final String body = new String(responseWrapper.getContentAsByteArray());

log.info(RESPONSE_LOG_FORMAT, method, url, statusCode, queryCount, timeTaken, memberId, body);
}

// MemberId를 가져온다. (memberId가 없을 경우, 인증된 사용자가 아니므로 NOT_AUTHENTICATED를 반환한다.)
private String getMemberId() {
String memberId = MDC.get(MEMBER_ID.getKey());
if (!StringUtils.hasText(memberId)) {
return NOT_AUTHENTICATED;
}
return memberId;
}

// API 요청에서 수행된 쿼리의 개수를 가져온다.
private int getQueryCount() {
return queryCounter.getQueryCount();
}

// MDC에 correlationId를 추가한다.
private void addCorrelationIdToMdc() {
MDC.put(CORRELATION_ID.getKey(), String.valueOf(UUID.randomUUID()));
}

// 쿼리 파라미터를 포함한 URL을 가져온다.
private String getUrlWithQueryParameters(final ContentCachingRequestWrapper requestWrapper) {
if (!StringUtils.hasText(requestWrapper.getQueryString())) {
return requestWrapper.getRequestURI();
}
return requestWrapper.getRequestURI() + "?" + requestWrapper.getQueryString();
}


}
16 changes: 16 additions & 0 deletions src/main/java/com/e2i/wemeet/config/log/MdcKey.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
package com.e2i.wemeet.config.log;

import lombok.Getter;

@Getter
public enum MdcKey {
CORRELATION_ID("correlationId"),
MEMBER_ID("memberId"),
;

private final String key;

MdcKey(String key) {
this.key = key;
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,60 @@
package com.e2i.wemeet.config.log.aspect;

import com.e2i.wemeet.config.log.MdcKey;
import java.util.HashMap;
import java.util.Map;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.MDC;
import org.springframework.util.StringUtils;

@Slf4j
@Aspect
public class ControllerLogAspect {

private static final String CONTROLLER_LOG_FORMAT_BEFORE_PROCEED = "[CONTROLLER-START]:: MEMBER_ID: {}, CLASS: {}, METHOD: {}, PARAMS: {}";
private static final String CONTROLLER_LOG_FORMAT_AFTER_PROCEED = "[CONTROLLER-END]:: MEMBER_ID: {}, CLASS: {}, METHOD: {}, RETURN_TYPE: {}, RETURN_VALUE: {}";
private static final String NOT_AUTHENTICATED = "none";

@Around("execution(* com.e2i.wemeet.controller..*.*(..))")
public Object verify(ProceedingJoinPoint joinPoint) throws Throwable {
MethodSignature signature = (MethodSignature) joinPoint.getSignature();

String className = joinPoint.getTarget().getClass().getSimpleName();
String methodName = signature.getMethod().getName();
Map<String, Object> parameters = getParameters(joinPoint, signature);
String memberId = getMemberId();

log.info(CONTROLLER_LOG_FORMAT_BEFORE_PROCEED, memberId, className, methodName, parameters);
Object proceed = joinPoint.proceed();

log.info(CONTROLLER_LOG_FORMAT_AFTER_PROCEED, memberId, className, methodName, signature.getReturnType().getSimpleName(), proceed);

return proceed;
}

private String getMemberId() {
String memberId = MDC.get(MdcKey.MEMBER_ID.getKey());
if (!StringUtils.hasText(memberId)) {
return NOT_AUTHENTICATED;
}
return memberId;
}

private Map<String, Object> getParameters(JoinPoint joinPoint, MethodSignature signature) {
Map<String, Object> parameterMap = new HashMap<>();

String[] parameterNames = signature.getParameterNames();
Object[] parameters = joinPoint.getArgs();

for (int i = 0; i < parameterNames.length; i++) {
parameterMap.put(parameterNames[i], parameters[i]);
}
return parameterMap;
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,30 @@
package com.e2i.wemeet.config.log.aspect;

import com.e2i.wemeet.config.log.module.ConnectionInvocationHandler;
import com.e2i.wemeet.config.log.module.QueryCounter;
import java.lang.reflect.Proxy;
import lombok.RequiredArgsConstructor;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;

@RequiredArgsConstructor
@Aspect
public class QueryCounterAspect {

private final QueryCounter apiQueryCounter;

/*
* database 와 connection 이 일어날 때마다 queryCount를 늘림
* */
@Around("execution(* javax.sql.DataSource.getConnection())")
public Object getConnection(final ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
final Object connection = proceedingJoinPoint.proceed();
return Proxy.newProxyInstance(
connection.getClass().getClassLoader(),
connection.getClass().getInterfaces(),
new ConnectionInvocationHandler(connection, apiQueryCounter)
);
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,58 @@
package com.e2i.wemeet.config.log.aspect;

import com.e2i.wemeet.config.log.MdcKey;
import java.util.HashMap;
import java.util.Map;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.MDC;
import org.springframework.util.StringUtils;

@Slf4j
@Aspect
public class ServiceLogAspect {

private static final String SERVICE_LOG_FORMAT_BEFORE_PROCEED = "[SERVICE-START] :: MEMBER_ID: {}, CLASS: {}, METHOD: {}, PARAMS: {}";
private static final String SERVICE_LOG_FORMAT_AFTER_PROCEED = "[SERVICE-END] :: MEMBER_ID: {}, CLASS: {}, METHOD: {}, RETURN_TYPE: {}, RETURN_VALUE: {}";
private static final String NOT_AUTHENTICATED = "none";

@Around("execution(* com.e2i.wemeet.service..*.*(..))")
public Object verify(ProceedingJoinPoint joinPoint) throws Throwable {
MethodSignature signature = (MethodSignature) joinPoint.getSignature();

String className = joinPoint.getTarget().getClass().getSimpleName();
String methodName = signature.getMethod().getName();
String memberId = getMemberId();

log.info(SERVICE_LOG_FORMAT_BEFORE_PROCEED, memberId, className, methodName, getParameters(joinPoint, signature));
Object proceed = joinPoint.proceed();

log.info(SERVICE_LOG_FORMAT_AFTER_PROCEED, memberId, className, methodName, signature.getReturnType().getSimpleName(), proceed);
return proceed;
}

private String getMemberId() {
String memberId = MDC.get(MdcKey.MEMBER_ID.getKey());
if (!StringUtils.hasText(memberId)) {
return NOT_AUTHENTICATED;
}
return memberId;
}

private Map<String, Object> getParameters(JoinPoint joinPoint, MethodSignature signature) {
Map<String, Object> parameterMap = new HashMap<>();

String[] parameterNames = signature.getParameterNames();
Object[] parameters = joinPoint.getArgs();

for (int i = 0; i < parameterNames.length; i++) {
parameterMap.put(parameterNames[i], parameters[i]);
}
return parameterMap;
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,32 @@
package com.e2i.wemeet.config.log.module;

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.Method;
import java.lang.reflect.Proxy;

/*
* Jdbc Connection 을 받아 오는 동적 프록시 객체
* */
public class ConnectionInvocationHandler implements InvocationHandler {

private final Object connection;
private final QueryCounter queryCounter;

public ConnectionInvocationHandler(Object connection, QueryCounter queryCounter) {
this.connection = connection;
this.queryCounter = queryCounter;
}

@Override
public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
final Object result = method.invoke(connection, args);
if (method.getName().equals("prepareStatement")) {
return Proxy.newProxyInstance(
result.getClass().getClassLoader(),
result.getClass().getInterfaces(),
new PreparedStatementInvocationHandler(result, queryCounter)
);
}
return result;
}
}
Loading