Skip to content

Commit f102528

Browse files
sukangpunchsukangpunch
authored
feat: API 성능 로깅, 쿼리 별 메트릭 전송 추가 (#602)
* feat: HTTP 요청/응답 로깅 필터 구현 - traceId 기반 요청 추적 - 요청/응답 로깅 - CustomExceptionHandler와 중복 로깅 방지 - Actuator 엔드포인트 로깅 제외 * feat: ExceptionHandler에 중복 로깅 방지 플래그 및 userId 로깅 추가 * feat: API 수행시간 로깅 인터셉터 추가 * feat: ApiPerf 인터셉터, Logging 필터 빈 등록 * refactor: logback 설정 변경 - info, warn, error, api_perf 로 로그 파일 분리해서 관리 * feat: 쿼리 별 수행시간 메트릭 모니터링 추가 * feat: 데이터소스 프록시 의존성 및 config 파일 추가 * feat: 데이터 소스 프록시가 metric을 찍을 수 있도록 listener 클래스 추가 * feat: 요청 시 method, uri 정보를 listener에서 활용하기 위해 RequestContext 및 관련 interceptor 추가 * refactor: 비효율적인 Time 빌더 생성 개선 - Time.builder 를 사용하면 매번 빌더를 생성하여 비효율적인 문제를 meterRegistry.timer 방식으로 해결 * feat: 로깅을 위해 HttpServeletRequest 속성에 userId 추가 * refactor: logback 설정 중 local은 console만 찍도록 수정 * refactor: FILE_PATTERN -> LOG_PATTERN 으로 수정 * test: TokenAuthenticationFilter에서 request에 userId 설정 검증 추가 - principal 조회 예외를 막기 위해 siteUserDetailsService given 추가 * refacotr: 코드 래빗 리뷰사항 반영 * test: 중복되는 테스트 제거 * refactor: 사용하지 않는 필드 제거 * refactor: 리뷰 내용 반영 * refactor: ApiPerformanceInterceptor에서 uri 정규화 관련 코드 제거 * refactor: ApiPerformanceInterceptor에서 if-return 문을 if-else 문으로 수정 * refactor: 추가한 interceptor 의 설정에 actuator 경로 무시하도록 셋팅 * refactor: 중복되는 의존성 제거 * refactor: 로깅 시 민감한 쿼리 파라미터 마스킹 - EXCLUDE_QUERIES 에 해당하는 쿼리 파라미터 KEY 값의 VALUE 를 masking 값으로 치환 * refactor: 예외 처리 후에도 Response 로그 찍도록 수정 * refactor: CustomExceptionHandler 원상복구 - Response 로그를 통해 user를 추적할 수 있으므로 로그에 userId 를 추가하지 않습니다 * refactor: 리뷰 사항 반영 * refactor: RequestContext 빌더 제거 * refactor: RequestContextInterceptor import 수정 * refactor: logback yml 파일에서 timestamp 서버 시간과 동일한 규격으로 수정 * refactor: ApiPerformanceInterceptor 에서 동일 내용 로그 중복으로 찍는 문제 수정 * fix: decode를 두 번 하는 문제 수정 * test: 로깅 관련 filter, interceptor 테스트 추가 * refactor: 코드래빗 리뷰사항 반영 * test: contains 로 비교하던 검증 로직을 isEqualTo 로 수정 * test: preHandle 테스트 에서 result 값을 항상 검증 * refactor: 단위테스트에 TestContainer 어노테이션 제거 * fix: conflict 해결
1 parent ddf29e2 commit f102528

16 files changed

Lines changed: 1351 additions & 24 deletions

File tree

‎build.gradle‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -68,6 +68,9 @@ dependencies {
6868
implementation 'org.hibernate.validator:hibernate-validator'
6969
implementation 'com.amazonaws:aws-java-sdk-s3:1.12.782'
7070
implementation 'org.springframework.boot:spring-boot-starter-websocket'
71+
72+
// Database Proxy
73+
implementation 'net.ttddyy.observation:datasource-micrometer:1.2.0'
7174
}
7275

7376
tasks.named('test', Test) {

‎src/main/java/com/example/solidconnection/common/config/datasource/DataSourceProxyConfig.java‎

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,29 @@
1+
package com.example.solidconnection.common.config.datasource;
2+
3+
import com.example.solidconnection.common.listener.QueryMetricsListener;
4+
import javax.sql.DataSource;
5+
import lombok.RequiredArgsConstructor;
6+
import net.ttddyy.dsproxy.support.ProxyDataSourceBuilder;
7+
import org.springframework.boot.autoconfigure.jdbc.DataSourceProperties;
8+
import org.springframework.context.annotation.Bean;
9+
import org.springframework.context.annotation.Configuration;
10+
import org.springframework.context.annotation.Primary;
11+
12+
@RequiredArgsConstructor
13+
@Configuration
14+
public class DataSourceProxyConfig {
15+
16+
private final QueryMetricsListener queryMetricsListener;
17+
18+
@Bean
19+
@Primary
20+
public DataSource proxyDataSource(DataSourceProperties props) {
21+
DataSource dataSource = props.initializeDataSourceBuilder().build();
22+
23+
return ProxyDataSourceBuilder
24+
.create(dataSource)
25+
.listener(queryMetricsListener)
26+
.name("main")
27+
.build();
28+
}
29+
}

‎src/main/java/com/example/solidconnection/common/config/web/WebMvcConfig.java‎

Lines changed: 26 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,17 @@
11
package com.example.solidconnection.common.config.web;
22

33
import com.example.solidconnection.common.interceptor.BannedUserInterceptor;
4+
import com.example.solidconnection.common.filter.HttpLoggingFilter;
5+
import com.example.solidconnection.common.interceptor.ApiPerformanceInterceptor;
6+
import com.example.solidconnection.common.interceptor.RequestContextInterceptor;
47
import com.example.solidconnection.common.resolver.AuthorizedUserResolver;
58
import com.example.solidconnection.common.resolver.CustomPageableHandlerMethodArgumentResolver;
69
import java.util.List;
710
import lombok.RequiredArgsConstructor;
11+
import org.springframework.boot.web.servlet.FilterRegistrationBean;
12+
import org.springframework.context.annotation.Bean;
813
import org.springframework.context.annotation.Configuration;
14+
import org.springframework.core.Ordered;
915
import org.springframework.web.method.support.HandlerMethodArgumentResolver;
1016
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
1117
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
@@ -17,6 +23,9 @@ public class WebMvcConfig implements WebMvcConfigurer {
1723
private final AuthorizedUserResolver authorizedUserResolver;
1824
private final CustomPageableHandlerMethodArgumentResolver customPageableHandlerMethodArgumentResolver;
1925
private final BannedUserInterceptor bannedUserInterceptor;
26+
private final HttpLoggingFilter httpLoggingFilter;
27+
private final ApiPerformanceInterceptor apiPerformanceInterceptor;
28+
private final RequestContextInterceptor requestContextInterceptor;
2029

2130
@Override
2231
public void addArgumentResolvers(List<HandlerMethodArgumentResolver> resolvers) {
@@ -27,8 +36,24 @@ public void addArgumentResolvers(List<HandlerMethodArgumentResolver> resolvers)
2736
}
2837

2938
@Override
30-
public void addInterceptors(InterceptorRegistry registry) {
39+
public void addInterceptors(InterceptorRegistry registry){
40+
registry.addInterceptor(apiPerformanceInterceptor)
41+
.addPathPatterns("/**")
42+
.excludePathPatterns("/actuator/**");
43+
44+
registry.addInterceptor(requestContextInterceptor)
45+
.addPathPatterns("/**")
46+
.excludePathPatterns("/actuator/**");
47+
3148
registry.addInterceptor(bannedUserInterceptor)
3249
.addPathPatterns("/posts/**", "/comments/**", "/chats/**", "/boards/**");
3350
}
51+
52+
@Bean
53+
public FilterRegistrationBean<HttpLoggingFilter> customHttpLoggingFilter() {
54+
FilterRegistrationBean<HttpLoggingFilter> filterBean = new FilterRegistrationBean<>();
55+
filterBean.setFilter(httpLoggingFilter);
56+
filterBean.setOrder(Ordered.HIGHEST_PRECEDENCE);
57+
return filterBean;
58+
}
3459
}

‎src/main/java/com/example/solidconnection/common/filter/HttpLoggingFilter.java‎

Lines changed: 156 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,156 @@
1+
package com.example.solidconnection.common.filter;
2+
3+
import jakarta.servlet.FilterChain;
4+
import jakarta.servlet.ServletException;
5+
import jakarta.servlet.http.HttpServletRequest;
6+
import jakarta.servlet.http.HttpServletResponse;
7+
import java.io.IOException;
8+
import java.net.URLDecoder;
9+
import java.nio.charset.StandardCharsets;
10+
import java.util.List;
11+
import lombok.RequiredArgsConstructor;
12+
import lombok.extern.slf4j.Slf4j;
13+
import org.slf4j.MDC;
14+
import org.springframework.http.HttpStatus;
15+
import org.springframework.stereotype.Component;
16+
import org.springframework.util.AntPathMatcher;
17+
import org.springframework.web.filter.OncePerRequestFilter;
18+
19+
@Slf4j
20+
@RequiredArgsConstructor
21+
@Component
22+
public class HttpLoggingFilter extends OncePerRequestFilter {
23+
24+
private static final AntPathMatcher PATH_MATCHER = new AntPathMatcher();
25+
private static final List<String> EXCLUDE_PATTERNS = List.of("/actuator/**");
26+
private static final List<String> EXCLUDE_QUERIES = List.of("token");
27+
private static final String MASK_VALUE = "****";
28+
29+
@Override
30+
protected void doFilterInternal(
31+
HttpServletRequest request,
32+
HttpServletResponse response,
33+
FilterChain filterChain
34+
) throws ServletException, IOException {
35+
36+
// 1) traceId 부여
37+
String traceId = generateTraceId();
38+
MDC.put("traceId", traceId);
39+
40+
boolean excluded = isExcluded(request);
41+
42+
// 2) 로깅 제외 대상이면 그냥 통과 (traceId는 유지: 추후 하위 레이어 로그에도 붙음)
43+
if (excluded) {
44+
try {
45+
filterChain.doFilter(request, response);
46+
} finally {
47+
MDC.clear();
48+
}
49+
return;
50+
}
51+
52+
printRequestUri(request);
53+
54+
try {
55+
filterChain.doFilter(request, response);
56+
printResponse(request, response);
57+
} finally {
58+
MDC.clear();
59+
}
60+
}
61+
62+
private boolean isExcluded(HttpServletRequest req) {
63+
String path = req.getRequestURI();
64+
for (String p : EXCLUDE_PATTERNS) {
65+
if (PATH_MATCHER.match(p, path)) {
66+
return true;
67+
}
68+
}
69+
return false;
70+
}
71+
72+
private String generateTraceId() {
73+
return java.util.UUID.randomUUID().toString().replace("-", "").substring(0, 16);
74+
}
75+
76+
private void printRequestUri(HttpServletRequest request) {
77+
String methodType = request.getMethod();
78+
String uri = buildDecodedRequestUri(request);
79+
log.info("[REQUEST] {} {}", methodType, uri);
80+
}
81+
82+
private void printResponse(
83+
HttpServletRequest request,
84+
HttpServletResponse response
85+
) {
86+
Long userId = (Long) request.getAttribute("userId");
87+
String uri = buildDecodedRequestUri(request);
88+
HttpStatus status = HttpStatus.valueOf(response.getStatus());
89+
90+
log.info("[RESPONSE] {} userId = {}, ({})", uri, userId, status);
91+
}
92+
93+
private String buildDecodedRequestUri(HttpServletRequest request) {
94+
String path = request.getRequestURI();
95+
String query = request.getQueryString();
96+
97+
if(query == null || query.isBlank()){
98+
return path;
99+
}
100+
101+
String decodedQuery = decodeQuery(query);
102+
String maskedQuery = maskSensitiveParams(decodedQuery);
103+
104+
return path + "?" + maskedQuery;
105+
}
106+
107+
private String decodeQuery(String rawQuery) {
108+
if(rawQuery == null || rawQuery.isBlank()){
109+
return rawQuery;
110+
}
111+
112+
try {
113+
return URLDecoder.decode(rawQuery, StandardCharsets.UTF_8);
114+
} catch (IllegalArgumentException e) {
115+
log.warn("Query 디코딩 실패 parameter: {}, msg: {}", rawQuery, e.getMessage());
116+
return rawQuery;
117+
}
118+
}
119+
120+
private String maskSensitiveParams(String decodedQuery) {
121+
String[] params = decodedQuery.split("&");
122+
StringBuilder maskedQuery = new StringBuilder();
123+
124+
for(int i = 0; i < params.length; i++){
125+
String param = params[i];
126+
127+
if(!param.contains("=")){
128+
maskedQuery.append(param);
129+
}else{
130+
int equalIndex = param.indexOf("=");
131+
String key = param.substring(0, equalIndex);
132+
133+
if(isSensitiveParam(key)){
134+
maskedQuery.append(key).append("=").append(MASK_VALUE);
135+
}else{
136+
maskedQuery.append(param);
137+
}
138+
}
139+
140+
if(i < params.length - 1){
141+
maskedQuery.append("&");
142+
}
143+
}
144+
145+
return maskedQuery.toString();
146+
}
147+
148+
private boolean isSensitiveParam(String paramKey) {
149+
for (String sensitiveParam : EXCLUDE_QUERIES){
150+
if(sensitiveParam.equalsIgnoreCase(paramKey)){
151+
return true;
152+
}
153+
}
154+
return false;
155+
}
156+
}

‎src/main/java/com/example/solidconnection/common/interceptor/ApiPerformanceInterceptor.java‎

Lines changed: 67 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,67 @@
1+
package com.example.solidconnection.common.interceptor;
2+
3+
import jakarta.servlet.http.HttpServletRequest;
4+
import jakarta.servlet.http.HttpServletResponse;
5+
import lombok.RequiredArgsConstructor;
6+
import lombok.extern.slf4j.Slf4j;
7+
import org.slf4j.Logger;
8+
import org.slf4j.LoggerFactory;
9+
import org.springframework.stereotype.Component;
10+
import org.springframework.web.servlet.HandlerInterceptor;
11+
12+
@Slf4j
13+
@RequiredArgsConstructor
14+
@Component
15+
public class ApiPerformanceInterceptor implements HandlerInterceptor {
16+
private static final String START_TIME_ATTRIBUTE = "startTime";
17+
private static final String REQUEST_URI_ATTRIBUTE = "requestUri";
18+
private static final int RESPONSE_TIME_THRESHOLD = 3_000;
19+
private static final Logger API_PERF = LoggerFactory.getLogger("API_PERF");
20+
21+
@Override
22+
public boolean preHandle(
23+
HttpServletRequest request,
24+
HttpServletResponse response,
25+
Object handler
26+
) throws Exception {
27+
28+
long startTime = System.currentTimeMillis();
29+
30+
request.setAttribute(START_TIME_ATTRIBUTE, startTime);
31+
request.setAttribute(REQUEST_URI_ATTRIBUTE, request.getRequestURI());
32+
33+
return true;
34+
}
35+
36+
@Override
37+
public void afterCompletion(
38+
HttpServletRequest request,
39+
HttpServletResponse response,
40+
Object handler,
41+
Exception ex
42+
) throws Exception {
43+
Long startTime = (Long) request.getAttribute(START_TIME_ATTRIBUTE);
44+
if(startTime == null) {
45+
return;
46+
}
47+
48+
long responseTime = System.currentTimeMillis() - startTime;
49+
50+
String uri = request.getRequestURI();
51+
String method = request.getMethod();
52+
int status = response.getStatus();
53+
54+
if (responseTime > RESPONSE_TIME_THRESHOLD) {
55+
API_PERF.warn(
56+
"type=API_Performance method_type={} uri={} response_time={} status={}",
57+
method, uri, responseTime, status
58+
);
59+
}
60+
else {
61+
API_PERF.info(
62+
"type=API_Performance method_type={} uri={} response_time={} status={}",
63+
method, uri, responseTime, status
64+
);
65+
}
66+
}
67+
}

‎src/main/java/com/example/solidconnection/common/interceptor/RequestContext.java‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,14 @@
1+
package com.example.solidconnection.common.interceptor;
2+
3+
import lombok.Getter;
4+
5+
@Getter
6+
public class RequestContext {
7+
private final String httpMethod;
8+
private final String bestMatchPath;
9+
10+
public RequestContext(String httpMethod, String bestMatchPath) {
11+
this.httpMethod = httpMethod;
12+
this.bestMatchPath = bestMatchPath;
13+
}
14+
}

‎src/main/java/com/example/solidconnection/common/interceptor/RequestContextHolder.java‎

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,18 @@
1+
package com.example.solidconnection.common.interceptor;
2+
3+
public class RequestContextHolder {
4+
private static final ThreadLocal<RequestContext> CONTEXT = new ThreadLocal<>();
5+
6+
public static void initContext(RequestContext requestContext) {
7+
CONTEXT.remove();
8+
CONTEXT.set(requestContext);
9+
}
10+
11+
public static RequestContext getContext() {
12+
return CONTEXT.get();
13+
}
14+
15+
public static void clear(){
16+
CONTEXT.remove();
17+
}
18+
}

‎src/main/java/com/example/solidconnection/common/interceptor/RequestContextInterceptor.java‎

Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,36 @@
1+
package com.example.solidconnection.common.interceptor;
2+
3+
import static org.springframework.web.servlet.HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE;
4+
5+
import jakarta.servlet.http.HttpServletRequest;
6+
import jakarta.servlet.http.HttpServletResponse;
7+
import org.springframework.stereotype.Component;
8+
import org.springframework.web.servlet.HandlerInterceptor;
9+
10+
@Component
11+
public class RequestContextInterceptor implements HandlerInterceptor {
12+
13+
@Override
14+
public boolean preHandle(
15+
HttpServletRequest request,
16+
HttpServletResponse response,
17+
Object handler
18+
) {
19+
String httpMethod = request.getMethod();
20+
String bestMatchPath = (String) request.getAttribute(BEST_MATCHING_PATTERN_ATTRIBUTE);
21+
22+
RequestContext context = new RequestContext(httpMethod, bestMatchPath);
23+
RequestContextHolder.initContext(context);
24+
25+
return true;
26+
}
27+
28+
@Override
29+
public void afterCompletion(
30+
HttpServletRequest request,
31+
HttpServletResponse response,
32+
Object handler, Exception ex
33+
) {
34+
RequestContextHolder.clear();
35+
}
36+
}

0 commit comments

Comments
 (0)