🔥개요
안녕하세요, 개발자 이동재입니다.
로그 관리 잘하고 계신가요?🤔
저는 부끄럽게도, 로그 관리를 그동안 꽤나 단순무식하게 해왔습니다.
회사에서는 회사 양식에 맞춰 설정을 따르다 보니 따로 신경 쓸 일이 없었고, 사이드 프로젝트에서는 AOP를 이용해 로그를 설정하긴 했지만, 로그 형식이 모니터링과 검색에 최적화되지 않아서 에러 로그를 확인하는 데 어려움이 있었습니다.
프론트엔드에서 이슈가 발생하면 에러 로그를 통해 바로 확인하지 못하고, 제가 직접 API 호출을 하거나, 클라이언트에게 요청을 다시 달라고 하는 경우가 많았습니다. 단순한 API 테스트가 아닌 이상, 이러한 방식으로 이슈를 확인해야 했죠.
그뿐만 아니라, 에러가 발생한 Controller나 Service에 그때그때 log를 추가하고, 에러를 해결한 후에는 다시 로그를 제거하는 작업을 반복했습니다. 정확한 에러 원인을 파악하기 위해 로그를 추가하고, 그 후 배포를 여러 차례 진행해야 했습니다.
(지금 생각하면 말도 안되게 불편해 보이지만, 예 제가 그 불편함을 견뎌내는 부지런한 사람이었습니다.😄)
계기
제가 로그 관리 방식을 개선해야겠다고 결심한 이유는 바로 이번에 새로 시작한 사이드 프로젝트를 진행하면서였습니다.
이전의 사이드 프로젝트는 지인들과 함께 정기적인 오프라인 모임을 가지며 진행했기 때문에, 로그로 확인하기 어려운 에러가 발생해도 "만나서 처리하지 뭐~"가 가능했습니다. 실제로 만나서 각자 코드를 실행해 보면 대부분 금방 원인을 찾을 수 있었어요.
하지만 이번 프로젝트는 철저히 온라인 기반으로 진행되었습니다. 매주 온라인 회의를 하긴 했지만, 정기적인 오프라인 모임이 없었기 때문에 "만나서 처리하지 뭐~"가 안되는 환경이었습니다. 혼자 테스트하기 어려운 에러가 발생하면 프론트엔드 개발자와 시간을 맞춰, 제가 모니터링하는 동안 에러가 발생하는 상황을 만들어 달라고 부탁해야 했습니다.
게다가 이번 프로젝트는 iOS 기반이라, 저는 AOS 폰을 써서 테스트 환경 구축이 쉽지 않았습니다🥹. 웹 기반 프로젝트였으면 개발 서버에 올려 테스트 환경을 만들 수 있었겠지만, 이번에는 그렇게 할 수 없었어요.
다행히 프론트엔드 개발자분이 천사처럼 도와주셔서 원활하게 진행되긴 했지만, 제가 프론트엔드 개발자였다면 이해하기 어려운 상황이었을 것 같아요.
그래서 "아.. 이대로는 안 되겠다" 싶어, 로그 관리와 모니터링 시스템을 전면 개선하기로 마음먹었습니다.
오늘은 로그 설정을 하면서 제가 고민했던 요구사항과 시행착오, 그리고 모니터링 방법까지 공유해 보려고 합니다.
요구사항
제가 로그 관리를 개선하면서 생각한 요구사항은 세 가지입니다.
- 모든 API 요청을 기록할 것
- 특정 API 요청에 대한 검색이 용이할 것
- 에러 발생 시, 에러와 관련된 상세 로그를 남길 것
당연한 요구사항이지만, 지금까지는 제대로 이루어지지 않고 있었습니다... 네 죄송합니다.😭
🤔고민
구현을 시작하기 전에 먼저 고민했던 부분이 있었어요.
관리 방식
일반적으로 Tomcat + war나 jar를 통해 배포하면 로그 파일이 생성되잖아요? 이때 로그 모니터링을 로그 파일을 통해 할지, ELK나 Grafana 같은 로그 관리 도구를 사용할지, 아니면 MongoDB 같은 DB를 사용할지를 고민했어요.
사실 이번 기회에 ELK 같은 로그 관리 도구를 도입해 로그 분석까지 가능한 환경을 구축해보고 싶었습니다. 하지만, 제 요구사항을 충족하기에는 오버스펙이었고, 러닝 커브도 부담스러워서 지금 당장은 적합하지 않다고 판단했어요. 나중에(가까운 시일 내에) ELK를 적용하게 되면, 해당 내용도 블로그에 적어볼게요.
DB에 저장하는 방법도 고려했지만, 필요 이상의 복잡성을 피하기 위해 포기했습니다. 앞서 말했듯이, 제가 로그 모니터링에서 원하는 것은 특정 API 호출 시 어떤 에러가 발생했는지를 쉽게 파악하는 것입니다. 복잡한 통계나 분석이 필요한 것은 아니기 때문에, DB에 저장하는 방식도 불필요하다고 생각했습니다.
결론적으로, 파일로 로그를 관리하기로 했습니다. 다만, 추후 ELK나 다른 로그 관리 도구로 전환할 가능성을 염두에 두고, 파일을 단순히 텍스트 형식으로 기록하는 대신
JSON형식으로 기록하여 나중에 손쉽게 전환할 수 있도록 준비했습니다.
구현 방식
API, 즉 HTTP 요청마다 로그를 남기기 위한 옵션으로 AOP, Interceptor, Filter가 있었는데 이 중에 어떤 걸 사용할지 고민이 되었어요, 최종적으로는 Interceptor로 구현하기로 했습니다.
1.
AOP (Aspect-Oriented Programming)
- 장점: 비즈니스 로직과 별개로 공통 관심사를 처리할 수 있어서, 깔끔한 코드 분리 가능. 메서드 호출 전후의 다양한 로깅을 쉽게 처리할 수 있음.
- 단점: HTTP 요청 전체를 다루는 데는 적합하지 않음. 특히 요청과 응답 바디를 캡처하거나, 요청 전후의 응답 시간을 측정하는 등 세밀한 제어가 필요할 때는
AOP보다는Interceptor나Filter가 더 적합함.
2.
Filter
장점: 서블릿 레벨에서 동작하며, 모든 HTTP 요청에 대해 처리할 수 있어 가장 하위 레벨에서 로깅 가능. 정적 리소스와 같은 비즈니스 로직 외의 요청도 처리할 수 있음.
단점: Spring MVC 레이어보다 하위에 위치하므로, 컨트롤러와의 상호작용이 적고, 컨트롤러 관련 정보를 직접적으로 다루기 어려움. 비즈니스 로직에서의 특정한 로깅보다는 전체적인 요청 전후 처리에 더 적합.
3.
Interceptor
장점:Spring MVC레이어에서 컨트롤러에 도달하기 전후에 동작하므로, 요청 전/후의 로깅 및 응답 시간 측정에 적합. 컨트롤러로 전달되는 정보를 쉽게 접근할 수 있으며, 요청과 응답을 자유롭게 다룰 수 있음. 특정 API 호출에 대한 로깅에 매우 적합.
단점: 서블릿 레벨보다는 한 단계 위에서 동작하므로, 정적 리소스나 다른 비즈니스 로직 외의 요청은 처리할 수 없음. 하지만 이 부분은 내가 원하는 범위에서는 크게 문제가 되지 않음.
선택 및 이유
결론적으로,Interceptor를 선택했습니다. HTTP 요청 전후의 로깅을 깔끔하게 처리할 수 있고, 컨트롤러와의 상호작용이 쉬워 특정 API 호출에서 어떤 문제가 발생했는지 추적하는 데 적합했기 때문이에요.
또한 AOP는 특정 메서드 단위에서 로깅을 하기에는 좋지만, HTTP 요청과 응답의 흐름 전체를 다루기에는 부족하다고 판단했습니다. Filter는 너무 하위 레벨에서 동작해 필요한 정보에 접근하는 데 한계가 있었기 때문에 적합하지 않다고 봤어요.
🛠️구현
이제 관리 방식과 구현에 대한 고민이 끝났으니, 본격적으로 구현해보겠습니다!
⚙️1. Interceptor 기본 구현
Spring Boot에서 Interceptor를 사용하려면 Interceptor 구현 뿐 아니라 Config 설정도 필요합니다. 차근차근 해볼게요.
Step 1: Gradle 설정
compileOnly 'org.projectlombok:lombok'
annotationProcessor 'org.projectlombok:lombok'
implementation 'org.springframework.boot:spring-boot-starter-web'Interceptor는 HandlerInterceptor 인터페이스를 통해 구현하므로, 이를 사용하기 위해 Spring Web 의존성을 추가해야 합니다.
Lombok은 @Slf4j를 사용하여 간편하게 로깅을 설정하기 위해 추가합니다.
Step 2: Interceptor 구현
Interceptor는 HandlerInterceptor 인터페이스를 구현하여 사용합니다. preHandle(요청 전), postHandle(요청 후), 그리고 afterCompletion(요청 완료 후)에 로그를 남길 수 있습니다.
저는 preHandle(요청 전)과 afterCompletion(요청 완료 후) 메서드를 사용하여 HTTP 요청 전후에 로그를 기록했습니다.
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;
import org.springframework.web.servlet.HandlerInterceptor;
@Slf4j
@Component
public class LoggingInterceptor implements HandlerInterceptor {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
// 요청 로깅
log.info("Request Method: [{}] URL: [{}]",request.getMethod(), request.getRequestURI());
return true; // 요청을 계속 진행
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
// 응답 로깅
log.info("Response Status: [{}]", response.getStatus());
}
}
preHandle에서는 Request의 Method와 URL을 기록하고, afterCompletion에서는 Response의 Status를 기록하도록 했습니다.
여기서 Response는 HTTP의 Status 코드를 의미합니다.
Step 3: WebConfig 설정
Interceptor에서 어떤 동작을 할지 설정해 주었으니, 이제 해당 Interceptor를 Spring에 등록해야 합니다. 등록은 WebMvcConfigurer를 구현한 설정 클래스에서 할 수 있습니다.
import lombok.RequiredArgsConstructor;
import org.springframework.context.annotation.Configuration;
import com.example.logging_example.interceptor.LoggingInterceptor;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
@Configuration
@RequiredArgsConstructor
public class WebConfig implements WebMvcConfigurer {
private final LoggingInterceptor loggingInterceptor; // Interceptor 생성자 주입
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(loggingInterceptor).addPathPatterns("/**"); // 모든 경로에 Interceptor 적용
}
}RequiredArgsConstructor를 사용해 LoggingInterceptor를 생성자로 주입하고, registry에 해당 Interceptor 구현체를 등록합니다.
위의 코드는 테스트 코드이기에 모든 경로 패턴("/**")에 Interceptor를 적용했지만, 실제 환경에서는 특정
Controller나URL을 제외할 수 있으니 참고해주세요!
Step 4: 결과 확인
로깅 설정을 완료했으니, 결과를 확인해봐야겠죠?😄
이를 위해 테스트 용 Controller를 작성합니다.
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.*;
@RestController
@RequestMapping("/api/logging")
public class LoggingController {
@GetMapping
public ResponseEntity<?> getTest() {
return ResponseEntity.ok().body("Get Test OK");
}
@PostMapping
public ResponseEntity<?> postTest() {
return ResponseEntity.ok().body("Post Test OK");
}
@DeleteMapping
public ResponseEntity<?> deleteTest() {
return ResponseEntity.ok().body("Delete Test OK");
}
@PatchMapping
public ResponseEntity<?> patchTest() {
return ResponseEntity.ok().body("Patch Test OK");
}
}
API 요청 시 로그가 제대로 찍히는지 확인하기 위해 대표적인 HTTP 메서드(GET, POST, DELETE, PATCH)에 대한 엔드포인트를 작성했습니다.
이제 요청을 보내 로그가 잘 찍히는지 확인해보면:
요청 및 응답 로그가 정상적으로 기록되는 것을 확인할 수 있습니다.
이제 Interceptor를 통해 기본적인 요청, 응답 로깅을 처리해줄 수 있게 되었습니다. 하지만 현재 로그만으로는 얻을 수 있는 정보가 너무 제한적이기 때문에, Request 요청 로그를 좀 더 구체적으로 기록할 필요가 있을 것 같습니다.
⚙️2. 'Request' 상세 로깅
기본적인 요청 로그만으로는 어떤 파라미터가 전송되었는지 확인하기 어렵습니다. 따라서 Request Param, Request Body, PathVariable 각 상황에 맞게 추가로 로깅을 설정하여 요청 정보를 더욱 구체적으로 기록해볼게요.
Step 1: Request Param
쿼리 파라미터의 경우 GET 요청에서 주로 사용되며, 이를 Request Param으로 로깅할 수 있습니다. HttpServletRequest의 getParameterNames()와 getParameter() 메서드를 사용해 쿼리 파라미터를 추출해서 기록합니다.
private Map<String, String> getRequestParams(HttpServletRequest request) {
Map<String, String> paramMap = new HashMap<>();
Enumeration<String> parameterNames = request.getParameterNames();
while (parameterNames.hasMoreElements()) {
String paramName = parameterNames.nextElement();
paramMap.put(paramName, request.getParameter(paramName));
}
return paramMap;
}위 getRequestParams 메서드를 통해 쿼리 파라미터를 Map 형태로 추출할 수 있으며, 이를 로깅에 활용할 수 있습니다.
Interceptor 적용
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
// Request Param 존재한다면 Logging 한다.
if (request.getParameterNames().hasMoreElements()) {
log.info("Request Method: [{}] URL: [{}] Params: [{}]",request.getMethod(), request.getRequestURI(), getRequestParams(request));
} else {
log.info("Request Method: [{}] URL: [{}]",request.getMethod(), request.getRequestURI());
}
return true; // 요청을 계속 진행
}API 요청시 Request Param이 있다면 추가로 로깅하도록 설정했습니다. 결과는 뒤에서 같이 확인할게요.
Step 2: Request Body
POST, PATCH, PUT과 같은 요청 메서드에서는 주로 Request Body를 사용해 데이터를 전송합니다. Request Param과 형식이 다르기 때문에 따로 처리를 해주어야 합니다.
Request Body를 로깅할 때 주의할 점
HttpServletRequest의 Request Body는 한 번 읽으면 다시 읽을 수 없습니다. 즉, Interceptor에서 Request Body를 읽어 로깅하면, 컨트롤러에서 해당 바디를 다시 읽을 수 없게 되어 정상적인 처리가 불가능해집니다.
위의 문제를 해결하기 위해서는 CustomHttpRequestWrapper를 사용하여 요청 본문을 미리 캐싱해 두어야 합니다.
Wrapper 클래스는 Request Body를 여러 번 읽을 수 있도록 InputStream을 내부적으로 캐싱하여 관리합니다.
Step 2-1: CustomHttpRequestWrapper 생성
CustomHttpRequestWrapper 클래스는 HttpServletRequestWrapper를 상속받아 Request Body를 한 번만 읽는 것이 아니라, 여러 번 읽을 수 있도록 처리해줍니다.
import jakarta.servlet.ReadListener;
import jakarta.servlet.ServletInputStream;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletRequestWrapper;
import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStream;
public class CustomHttpRequestWrapper extends HttpServletRequestWrapper {
private byte[] requestBody;
public CustomHttpRequestWrapper(HttpServletRequest request) throws IOException {
super(request);
// Request Body를 바이트 배열로 저장해 여러 번 읽을 수 있도록 캐싱
InputStream is = request.getInputStream();
ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream();
byte[] buffer = new byte[1024];
int length;
while ((length = is.read(buffer)) != -1) {
byteArrayOutputStream.write(buffer, 0, length);
}
this.requestBody = byteArrayOutputStream.toByteArray();
}
@Override
public ServletInputStream getInputStream() {
ByteArrayInputStream byteArrayInputStream = new ByteArrayInputStream(this.requestBody);
return new ServletInputStream() {
@Override
public int read() {
return byteArrayInputStream.read();
}
@Override
public boolean isFinished() {
return byteArrayInputStream.available() == 0;
}
@Override
public boolean isReady() {
return true;
}
@Override
public void setReadListener(ReadListener readListener) {
// Not implemented
}
};
}
public byte[] getRequestBody() {
return this.requestBody;
}
}
해당 클래스는 Request Body를 바이트 배열로 캐싱하여 여러 번 읽을 수 있도록 해줍니다.
getInputStream() 메서드는 항상 이 바이트 배열을 반환하므로, Controller에서도 문제 없이 Request Body를 사용할 수 있게 됩니다.
Step 2-2: Filter 설정
위에서 작성한 CustomHttpRequestWrapper가 모든 요청에서 적용될 수 있도록 Filter를 설정해야 합니다. Filter를 통해 Interceptor와 Controller 둘 다에서 Request Body를 읽을 수 있도록 할 수 있습니다.
import com.example.logging_example.wrapper.CustomHttpRequestWrapper;
import jakarta.servlet.*;
import jakarta.servlet.http.HttpServletRequest;
import org.springframework.stereotype.Component;
import java.io.IOException;
@Component
public class RequestWrapperFilter implements Filter {
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
if (request instanceof HttpServletRequest) {
HttpServletRequest httpRequest = (HttpServletRequest) request;
CustomHttpRequestWrapper requestWrapper = new CustomHttpRequestWrapper(httpRequest);
chain.doFilter(requestWrapper, response); // CustomHttpRequestWrapper로 감싼 후 체인 진행
} else {
chain.doFilter(request, response);
}
}
}해당 RequestWrapperFilter는 모든 요청을 CustomHttpRequestWrapper로 감싸줍니다.
Step 2-3: Interceptor 적용
이제 Interceptor는 HttpServletRequest가 CustomHttpRequestWrapper로 래핑되었는지 확인한 후, 래핑된 요청의 Request Body를 읽어 로깅합니다.
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
// request가 CustomHttpRequestWrapper로 래핑되어 있는지 확인
if (request instanceof CustomHttpRequestWrapper) {
CustomHttpRequestWrapper requestWrapper = (CustomHttpRequestWrapper) request;
String requestBody = new String(requestWrapper.getRequestBody());
// Request Body가 있을 경우 로깅
if (!requestBody.isEmpty()) {
log.info("Request Method: [{}] URL: [{}] Body: [{}]", request.getMethod(), request.getRequestURI(), requestBody);
}
}
// Request Param 존재한다면 Logging 한다.
if (request.getParameterNames().hasMoreElements()) {
log.info("Request Method: [{}] URL: [{}] Params: [{}]",request.getMethod(), request.getRequestURI(), getRequestParams(request));
}
else {
log.info("Request Method: [{}] URL: [{}]",request.getMethod(), request.getRequestURI());
}
return true; // 요청을 계속 진행
}지금까지의 흐름을 정리해보면 다음과 같습니다.
1. Filter에서 요청 감싸기:
RequestWrapperFilter는 모든 HTTP 요청을 감시하고, HttpServletRequest 타입의 요청일 경우CustomHttpRequestWrapper로 감싸서 전달합니다.
2. Interceptor에서 Request Body 읽기:
필터를 거친 후, 요청은 인터셉터로 넘어갑니다. 인터셉터에서 CustomHttpRequestWrapper의getInputStream()메서드를 통해 Request Body를 읽습니다. CustomHttpRequestWrapper는 내부적으로 Request Body를 메모리에 저장해 두고, 여러 번 읽을 수 있도록 해주기 때문에 인터셉터에서 읽더라도 InputStream은 초기화되지 않고 재사용 가능합니다.
3. Controller에서 Request Body 읽기:
인터셉터에서 Request Body를 읽더라도 CustomHttpRequestWrapper가 요청을 감싸고 있기 때문에, 컨트롤러에서도 동일한 Request Body를 다시 읽을 수 있습니다.
Step 3: PathVariable
PathVariable은 요청 경로의 일부분으로 사용되는 변수입니다. 예를 들어, /api/logging/{id}와 같은 경로에서 {id} 값이 PathVariable이 됩니다. 이 값을 로깅하려면 HandlerMethodArgumentResolver를 통해 해당 변수를 Interceptor에서 로깅할 수 있습니다.
Interceptor 적용
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
// PathVariable Logging
if (handler instanceof HandlerMethod) {
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
if (attributes != null) {
HttpServletRequest currentRequest = attributes.getRequest();
Map<String, String> pathVariables = (Map<String, String>) currentRequest.getAttribute(HandlerMapping.URI_TEMPLATE_VARIABLES_ATTRIBUTE);
if (pathVariables != null) {
log.info("Request Method: [{}] URL: [{}] pathVariables: [{}]", request.getMethod(), request.getRequestURI(), pathVariables);
return true; // 요청을 계속 진행
}
}
}
// 기본 요청
log.info("Request Method: [{}] URL: [{}]",request.getMethod(), request.getRequestURI());
return true; // 요청을 계속 진행
}
위 코드는 HandlerMethod인 경우 경로 pathVariables을 추출해 로깅합니다!
Step 4: 결과 확인
모든 Request 상세 로깅 설정이 끝났으니, 테스트를 위해 Controller를 추가 생성 후 결과를 확인해보겠습니다.
import com.example.logging_example.controller.request.PostRecord;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.*;
@RestController
@RequestMapping("/api/request/logging")
public class RequestLoggingController {
@GetMapping
public ResponseEntity<?> getParamTest(@RequestParam String name) {
return ResponseEntity.ok().body("getParamTest OK");
}
@PostMapping
public ResponseEntity<?> postBodyTest(@RequestBody PostRecord record) {
return ResponseEntity.ok().body("postBodyTest OK");
}
@PatchMapping("/{id}")
public ResponseEntity<?> patchPathVariableTest(@PathVariable String id) {
return ResponseEntity.ok().body("patchPathVariableTest OK");
}
}
GET은 Request Param, POST는 Body, PATCH는 PathVariable을 테스트하기 위해 각각의 엔드포인트를 추가한 후 테스트를 합니다!
이 후 테스트 결과를 확인하면:
각 요청 상황에 따라 설정한 대로 로그가 잘 기록되는 것을 확인할 수 있습니다.
⚙️3. 'Response' 상세 로깅
기본적인 응답 로그만으로는 성공, 실패 여부만 확인할 수 있어요.
하지만 응답 로그에 서버가 어떤 응답을 보냈는지 를 기록하면 더 자세한 정보를 쉽게 파악할 수 있습니다.
지금부터 Response Body(어떤 응답을 보냈는지)을 추가해보겠습니다!
Step 1: CustomWrapper 생성
HttpServletResponse는 Request와 마찬가지로 한 번 응답을 반환하면 그 내용을 다시 읽을 수 없습니다. 따라서, CustomHttpRequestWrapper와 유사하게,CustomResponseWrapper를 만들어 응답 내용을 캐싱해야 합니다.
import jakarta.servlet.ServletOutputStream;
import jakarta.servlet.WriteListener;
import jakarta.servlet.http.HttpServletResponse;
import jakarta.servlet.http.HttpServletResponseWrapper;
import java.io.ByteArrayOutputStream;
import java.io.PrintWriter;
public class CustomHttpResponseWrapper extends HttpServletResponseWrapper {
private final ByteArrayOutputStream outputStream = new ByteArrayOutputStream();
private final PrintWriter writer = new PrintWriter(outputStream);
public CustomHttpResponseWrapper(HttpServletResponse response) {
super(response);
}
@Override
public ServletOutputStream getOutputStream() {
return new ServletOutputStream() {
@Override
public boolean isReady() {
return true;
}
@Override
public void setWriteListener(WriteListener listener) {
}
@Override
public void write(int b) {
outputStream.write(b);
}
};
}
@Override
public PrintWriter getWriter() {
return writer;
}
public byte[] getResponseData() {
writer.flush();
return outputStream.toByteArray();
}
}
위의 Wrapper 클래스는 HttpServletResponseWrapper를 확장하여, 응답 데이터를 바이트 배열로 저장하고, Interceptor에서 이 데이터를 읽어 로그로 남길 수 있도록 합니다.
Step 2: Filter 설정
import com.example.logging_example.wrapper.CustomHttpResponseWrapper;
import jakarta.servlet.*;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.stereotype.Component;
import java.io.IOException;
@Component
public class ResponseWrapperFilter implements Filter {
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
if (response instanceof HttpServletResponse) {
CustomHttpResponseWrapper responseWrapper = new CustomHttpResponseWrapper((HttpServletResponse) response);
chain.doFilter(request, responseWrapper);
// 응답 데이터가 null이거나 비어있지 않은 경우에만 클라이언트로 출력
byte[] responseData = responseWrapper.getResponseData();
if (responseData != null && responseData.length > 0) {
response.getOutputStream().write(responseData);
}
} else {
chain.doFilter(request, response);
}
}
}
Filter에서 모든 응답을 CustomHttpResponseWrapper로 감싸도록 설정합니다.
해당 Filter는 HttpServletResponse를
CustomHttpResponseWrapper로 래핑한 뒤 요청을 처리하고, 응답 데이터(Response Body)가 존재하는 경우 이를 클라이언트로 반환합니다.
Filter 설정을 통해 Interceptor에서 Response Body를 읽음에도, 클라이언트가 정상적으로 Response Body를 받을 수 있게 됩니다.
Step 3: Interceptor 적용
Interceptor의 afterCompletion 메서드에서 CustomResponseWrapper를 통해 Response Body를 로깅합니다.
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws JsonProcessingException {
// Response Logging
if (response instanceof CustomHttpResponseWrapper responseWrapper) {
byte[] responseData = responseWrapper.getResponseData();
if (responseData != null && responseData.length > 0) {
String responseBody = new String(responseData);
ObjectMapper mapper = new ObjectMapper();
Object json = mapper.readValue(responseBody, Object.class);
String prettyBody = mapper.writeValueAsString(json);
log.info("Response Status: [{}] URL: [{}] Body: [{}]", response.getStatus(), request.getRequestURI(), prettyBody);
} else {
log.info("Response Status: [{}] URL: [{}] Body: [Empty]", response.getStatus(), request.getRequestURI());
}
} else {
log.info("Response Status: [{}] URL: [{}]", response.getStatus(), request.getRequestURI());
}
}
CustomHttpResponseWrapper로 래핑된 Response의 Status, URL, Response Body를 JSON 형식으로 로깅합니다.
Response Body가 비어 있으면 [Empty]로 표시하며, Response Body가 없는 일반 응답은 Status, URL만 로깅합니다.
Step 4: 결과 확인
모든 Response 상세 로깅 설정을 완료했으니, 테스트를 위한 Controller를 추가 작성 후 테스트 해볼게요.
@RestController
@RequestMapping("/api/response/logging")
public class ResponseLoggingController {
@GetMapping
public ResponseEntity<?> testResponseBodyByGet() {
ResponseTestRecord responseTestRecord = new ResponseTestRecord("1", "GET");
return ResponseEntity.ok().body(responseTestRecord);
}
@PostMapping
public ResponseEntity<?> testResponseBodyByPost() {
ResponseTestRecord responseTestRecord = new ResponseTestRecord("1", "POST");
return ResponseEntity.ok().body(responseTestRecord);
}
@DeleteMapping
public ResponseEntity<?> testResponseBodyByDelete() {
return ResponseEntity.ok().build();
}
}
public record ResponseTestRecord(String id, String method) {
}
GET, POST는 Response Body를 성공적으로 반환하는 걸 테스트하고, DELETE는 Respons Body가 없을 때도 잘 동작하는지를 테스트합니다.
GET 테스트 결과:
Interceptor에서도 Response Body를 성공적으로 로깅하고 있고 클라이언트도 데이터를 잘 반환받고 있는 걸 확인할 수 있습니다.
POST 테스트 결과:
Interceptor에서도 Response Body를 성공적으로 로깅하고 있고 클라이언트도 데이터를 잘 반환받고 있는 걸 확인할 수 있습니다.
DELETE 테스트 결과:
ResponseBody가 없을 때는 Body: [Empty] 로 잘 표시되고 있는걸 확인할 수 있습니다.
⚙️4. 예외 발생 로깅
API가 성공적으로 동작하는 상황에서는 로깅이 잘 이루어졌지만, 에러가 발생할 경우 단순히 콘솔 로그만 출력되어 정확히 어떤 부분에서 문제가 발생했는지 파악하기 어려웠습니다.
이를 개선하고자, 예외 발생 시 로깅 및 적절한 응답 반환을 위해 GlobalExceptionHandler를 설정했습니다.
@Slf4j
@RestControllerAdvice
@RequiredArgsConstructor
public class GlobalExceptionHandler {
@ExceptionHandler(BusinessException.class)
public ResponseEntity<CommonErrorResponse> handleCustomException(BusinessException exception) {
exception.printStackTrace();
CommonErrorCode errorCode = exception.getErrorCode();
CommonErrorResponse errorResponse = CommonErrorResponse.of(errorCode);
return ResponseEntity.badRequest().body(errorResponse);
}
}위 설정은 BusinessException 발생 시 미리 지정된 로직을 수행할 수 있게 해줍니다.
@Getter
public class BusinessException extends RuntimeException {
private final CommonErrorCode errorCode;
public BusinessException(CommonErrorCode errorCode) {
this.errorCode = errorCode;
}
}
@Getter
@AllArgsConstructor
public enum TestErrorCode implements CommonErrorCode {
GET_TEST_ERROR("301","GET_TEST_ERROR"),
POST_TEST_ERROR("302","POST_TEST_ERROR"),
DELETE_TEST_ERROR("303","DELETE_TEST_ERROR");
private final String code;
private final String message;
}그리고 예외 처리 설정을 테스트하기 위해 TestErrorCode와 예외가 발생하도록 설정된 TestController를 추가했습니다.
@RestController
@RequestMapping("/api/exception/logging")
public class ExceptionLoggingController {
@GetMapping
public ResponseEntity<?> testExceptionByGet() {
throw new BusinessException(TestErrorCode.GET_TEST_ERROR);
}
@PostMapping
public ResponseEntity<?> testExceptionByPost() {
throw new BusinessException(TestErrorCode.POST_TEST_ERROR);
}
@DeleteMapping
public ResponseEntity<?> testExceptionByDelete() {
throw new BusinessException(TestErrorCode.DELETE_TEST_ERROR);
}
}테스트 결과, 예상대로 예외가 잘 로깅되고 클라이언트에게도 올바른 응답이 반환되는 것을 확인할 수 있었습니다.
이렇게 예외처리 및 로깅을 통해 컨트롤러 단에서뿐만 아니라 서비스 단에서 발생하는 예외도 Service -> Handler -> Client 흐름으로 처리할 수 있어 단계별 역할 분리가 명확해집니다.
또한, 특정 비즈니스 로직이나 엔드포인트에서 발생할 수 있는 예외에 맞는 처리를 사전에 설정함으로써 일관된 로그가 쌓이도록 할 수 있습니다.
⚙️5. id, duratiotn 추가
로깅 설정을 통해 Request와 Response에 필요한 데이터를 기록하면서 로깅 활용도가 크게 향상되었습니다. 하지만 프로젝트에 실제 적용해보니 특정 API 요청을 빠르게 찾기 어려운 문제가 있었습니다.
제가 세운 로깅 요구사항 중 특정 API 요청에 대한 검색 용이성을 충분히 만족시키지 못했습니다.
에러 로그와 타임라인 덕분에 비교적 추적이 쉬워졌지만, 여전히 직관적 검색이라는 목표에는 미치지 못했습니다. 그래서 각 로그에 고유 ID를 추가해 특정 API 로그를 쉽게 식별하고자 했습니다.
또한, 요청에 걸린 시간을 확인하기 위해 API 요청과 응답 간 소요 시간을 기록하도록 했습니다. 다양한 API 호출로 화면이 느려지는 경우, 어느 API가 원인인지 파악하는 데 유용할 것 같아서입니다. 아직 duration 데이터로 뚜렷한 성과를 얻지는 못했지만, 의미 있는 데이터가 쌓이면 추후 블로그에 추가하겠습니다.
서론이 길었네요. 바로 ID, duration 추가해보겠습니다.
Step 1: preHandle 설정
preHandle에서 각 API 요청의 고유 ID를 생성하고, 요청 시간을 request 객체에 저장합니다.
클라이언트에게 requestId 전달을 위해 response 객체에 requestId를 미리 설정해줍니다. afterCompletion에 들어오기 전에 Wrapper로 response를 포장하므로, afterCompletion 단계에서 requestId를 추가해도 클라이언트에 전달되지 않습니다. 따라서 preHandle에서 설정해야 합니다.
가독성을 위해 기본 로깅을 예시로 보겠습니다.
저는 테스트용으로
UUID를 사용했지만, 상황에 맞게 규칙을 설정하여 구현하는 것이 좋습니다.
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
String requestId = UUID.randomUUID().toString();
request.setAttribute("X-Request-ID", requestId);
response.addHeader("X-Request-ID", requestId);
long startTime = System.currentTimeMillis();
request.setAttribute("startTime", startTime);
// 기본 요청
log.info("Request Method: [{}] id: [{}] URL: [{}]", request.getMethod(), requestId, request.getRequestURI());
return true; // 요청을 계속 진행
}Step 2: afterCompletion 설정
afterCompletion에서 request 객체에 저장된 ID를 조회하여 로그에 기록하고, 요청 시간과 응답 시간을 비교하여 duration을 계산한 후 로그에 추가합니다.
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws JsonProcessingException {
String requestId = (String) request.getAttribute("X-Request-ID");
long startTime = (Long) request.getAttribute("startTime");
long duration = System.currentTimeMillis() - startTime;
log.info("Response Status: [{}] id: [{}] duration: [{}] URL: [{}]", response.getStatus(), requestId, duration, request.getRequestURI());
}
}Step 3: 결과 확인
위에서 만들어두었던 TestController를 통해 테스트 해보겠습니다.
성공
UUID로 생성한 RequestId가 Log에도 잘 뜨고 Client Header에도 잘 담겨 있는걸 확인할 수 있습니다.
실패
예외 발생 시에도 RequestId가 잘 찍히는 모습을 확인할 수 있습니다.
⚙️6. 모니터링
로그 설정을 완료했으니 운영 중 로그를 모니터링하는 방법을 소개해볼게요.
애플리케이션 운영 중 로그를 확인할 때는 보통 두 가지 상황이 발생합니다.
에러가 발생했을 때 - 에러 로그를 찾아서 원인을 분석하는 경우
테스트 중 동작 확인 - 애플리케이션이 정상적으로 동작하는지 실시간 로그를 통해 확인하는 경우
서버 설정
환경: CentOS 7, jar 파일 배포
저는 Java 애플리케이션을 jar 파일로 빌드하고, CentOS 7에서 nohup을 이용하여 백그라운드에서 실행하는 환경을 기준으로 설명드리겠습니다.
nohup java -jar [project명].jar &위 명령어를 실행하면, nohup.out이라는 로그 파일이 생성됩니다. 아래 예시에서도 nohup.out 파일명을 기준으로 설명하겠습니다.
실시간 모니터링
실시간으로 로그를 모니터링하고자 할 때는 tail -f 명령어를 사용합니다. -f 옵션은 새로운 로그가 추가될 때마다 업데이트된 내용을 실시간으로 확인할 수 있게 해줍니다.
아래 명령어에서 -100은 기존 로그에서 마지막 100줄을 포함해 표시하라는 의미입니다.
tail -100f nohup.out
실시간으로 업데이트 되는 로그를 확인할 수 있습니다.
특정 로그 검색
이제 API 요청 시간을 일일이 확인하지 않아도, 요청별로 생성된 RequestId를 통해 로그를 쉽게 찾을 수 있습니다.
특정 값을 검색하려면 grep 명령어를 사용합니다.
grep "[검색어]" nohup.out예시
API 호출 결과에서 Header에 포함된 RequestId를 확인할 수 있습니다.
예를 들어, RequestId가 "abe5c325-f217-414c-bbed-b02a61fdb6ca"라면 다음과 같이 검색할 수 있습니다:
grep "abe5c325-f217-414c-bbed-b02a61fdb6ca" nohup.out
해당 명령어를 실행하면 해당 requestId와 관련된 요청 및 응답 로그가 nohup.out 파일에서 검색되어 잘 나타납니다.
에러 로그 검색
에러 로그를 확인할 때는 단순히 로그만 보는 것이 아니라, Exception 로그까지 함께 확인해야 하는 경우가 많습니다. 이를 위해 grep 명령어에 약간의 Option을 추가할 수 있습니다.
grep Option
- A (after): 검색된 라인 이후의 로그를 함께 표시
- B (before): 검색된 라인 이전의 로그를 함께 표시
- C (after & before): 검색된 라인 전후의 로그를 함께 표시
에러 로그는 보통 Request 로그 이후에 생성되므로, -A 옵션을 사용하여 특정 에러 로그 이후의 내용을 확인해 보겠습니다.
아래 명령어는 검색한 로그 이후 10줄의 추가 로그를 함께 보여줍니다:
grep -A 10 "d2ca6a9b-a498-4b39-af63-871227e02503" nohup.out예시
Exception을 발생시키는 API를 호출합니다.
이후, 해당 API의 RequestId로 로그 파일을 검색해 봅니다. 옵션 없이 grep 명령어를 사용하여 RequestId를 검색해도 에러 로그는 보이지 않습니다:
grep "d2ca6a9b-a498-4b39-af63-871227e02503" nohup.out
에러 로그와 함께 이후의 추가 로그를 확인하고자 할 때는 -A 옵션을 추가해 검색합니다. 아래 명령어는 지정한 RequestId와 그 이후의 10줄을 함께 출력합니다:
grep -A 10 "d2ca6a9b-a498-4b39-af63-871227e02503" nohup.out
이 명령어를 사용하면, 예외 로그까지 포함된 결과를 확인할 수 있습니다:
숫자 10은 보여주고자 하는 줄 수를 의미하며, 상황에 따라 필요한 만큼 늘릴 수 있습니다. 이를 통해 에러가 발생한 요청의 전체 로그 흐름을 쉽게 파악할 수 있습니다.
좋은 글 감사합니다!