Spring
AOP를 이용하여 API 로깅하기 (RequestBody, ResponseBody)
김예나
2025. 2. 27. 12:31
AOP
- 관점 지향 프로그래밍
- 반복되고 공통적으로 사용되는 부분을 분리
- 부가적인 기능을 핵심 로직으로부터 분리하여 핵심로직은 오로지 자신에게만 집중할 수 있음
발생한 문제 : NPE
LogAspect를 모두 작성하고 실행하려고 하는데 NullPointerException이 발생했다
Caused by: java.lang.NullPointerException: null
첫 번째 시도 : HttpServletRequest 수정
HttpServletRequest를 불러오는 부분에서 문제가 있었나 싶어서 해당 부분을 인텔리제이가 추천하는 코드로 변경했다
변경 전
HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest();
변경 후
HttpServletRequest request = ((ServletRequestAttributes) Objects.requireNonNull(RequestContextHolder.getRequestAttributes())).getRequest();
하지만 동일한 에러는 계속 발생했다
해결 : Pointcut 수정
기존에 작성했던 포인트컷은 @Pointcut("execution(* ..Admin.(..))") 이다
요구사항에서 로깅을 찍어야 하는 컨트롤러는 모두 이름에 Admin이 들어가야 했기 때문에 저렇게 작성을 해줬는데 뭔가 저 포인트컷의 내용이 모호하게 잡혀있어서 제대로 반영되지 못하고 AOP가 모든 요청에 대해서 실행하는 것 같은 기분이 들었다
그래서 좀 더 명시적으로 포인트컷을 수정했다!
@Pointcut("execution(* org.example.expert.domain.user.controller.UserAdminController.changeUserRole(..))")
public void userAdminController() {
}
@Pointcut("execution(* org.example.expert.domain.comment.controller.CommentAdminController.CommentAdminController(..))")
public void commentAdminController() {
}
패키지 경로부터 시작해서 아예 관리자 컨트롤러 내부에 있는 메서드까지 명시하니까 에러가 사라지고 잘 작동했다!
발생한 문제 : HttpServletRequest의 getInputStream() 호출 시 에러 발생
requestBody내역을 로그에 찍어야 하기 때문에 LogAspect에서 getInputStream()을 호출하는 코드를 작성했다!
public String getRequestBody(HttpServletRequest request) throws IOException {
ObjectMapper objectMapper = new ObjectMapper();
return objectMapper.readTree(request.getInputStream()).toString();
}
하지만 에러가 발생했다
Request processing failed: java.lang.IllegalStateException: getInputStream() has already been called for this request
HTTP 요청에 대해 getInputStream() 메서드를 한 번 이상 호출했을 때 발생하는 에러가 발생한 것이다!
찾아보니 HttpServletRequest에서 Stream형태로 RequestBody에 접근해 데이터를 가져갈경우에 스트림이 소비되면서 딱 한번만 읽을 수 있기 때문에 getInputStream() 또는 getReader()를 호출하면, 스트림이 소비되어 이후 다시 읽을 수 없다는 것이다
AOP를 사용하면서 먼저 RequestBody를 읽어서 스트림을 소비하고, 그 다음에 컨트롤러에서 한번 더 읽으려고 했는데 이미 스트림은 소비된 후라서 발생하게 된 것!!
해결 : HttpServletRequest의 Body를 여러번 읽을 수 있도록 바꾸기
RequestWrapper 추가
@Getter
public class RequestWrapper extends HttpServletRequestWrapper {
// 요청 바디를 저장하는 변수 (다시 읽을 수 있도록 캐싱)
private final String body;
public RequestWrapper(HttpServletRequest request) {
super(request);
StringBuilder stringBuilder = new StringBuilder();
try (BufferedReader bufferedReader = request.getReader()) { // 요청 바디를 읽을 BufferedReader 생성
char[] charBuffer = new char[128]; // 128자씩 읽어올 버퍼 생성
int bytesRead;
while ((bytesRead = bufferedReader.read(charBuffer)) > 0) {
// 읽어온 데이터를 StringBuilder에 추가
stringBuilder.append(charBuffer, 0, bytesRead);
}
} catch (IOException e) {
// 요청 바디를 읽다가 예외가 발생하면 400 Bad Request 예외 발생
throw new BadRequestException();
}
// 읽은 요청 바디를 문자열로 변환하여 저장
body = stringBuilder.toString();
}
@Override
public ServletInputStream getInputStream() {
// 저장된 body 문자열을 ByteArrayInputStream으로 변환 (다시 읽을 수 있도록 함)
final ByteArrayInputStream byteArrayInputStream = new ByteArrayInputStream(body.getBytes());
return new ServletInputStream() {
@Override
public boolean isFinished() {
return false; // 스트림이 끝났는지 여부 (false로 설정하여 계속 읽을 수 있도록 함)
}
@Override
public boolean isReady() {
return false; // 스트림이 준비되었는지 여부 (false로 설정)
}
@Override
public void setReadListener(ReadListener readListener) {
throw new UnsupportedOperationException(); // 비동기 읽기 미지원
}
@Override
public int read() {
return byteArrayInputStream.read(); // 저장된 요청 바디를 한 글자씩 읽어서 반환
}
};
}
@Override
public BufferedReader getReader() {
// getInputStream()을 기반으로 BufferedReader 생성하여 반환 (요청 바디를 여러 번 읽을 수 있도록 함)
return new BufferedReader(new InputStreamReader(this.getInputStream()));
}
}
필터에 적용
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
HttpServletRequest httpRequest = (HttpServletRequest) request;
HttpServletResponse httpResponse = (HttpServletResponse) response;
request = new RequestWrapper(httpRequest);
발생한 문제 : HttpServletResponse의 Body조회 불가
응답 객체의 body도 조회해야 했기 때문에 Request의 Body를 조회할 때처럼 유사하게 하면 된다고 생각했다
첫 번째 시도 : RequestWrapper 사용
public class RequestWrapper extends HttpServletRequestWrapper {
private final String body; // 요청 본문을 저장할 변수
public RequestWrapper(HttpServletRequest request) throws IOException {
super(request);
StringBuilder stringBuilder = new StringBuilder();
BufferedReader bufferedReader = request.getReader();
String line;
while ((line = bufferedReader.readLine()) != null) {
stringBuilder.append(line).append("\n");
}
body = stringBuilder.toString(); // 본문 저장
}
@Override
public BufferedReader getReader() {
return new BufferedReader(new InputStreamReader(new ByteArrayInputStream(body.getBytes())));
}
@Override
public ServletInputStream getInputStream() {
ByteArrayInputStream byteArrayInputStream = new ByteArrayInputStream(body.getBytes());
return new ServletInputStream() {
@Override
public boolean isFinished() {
return false;
}
@Override
public boolean isReady() {
return true;
}
@Override
public void setReadListener(ReadListener readListener) {}
@Override
public int read() {
return byteArrayInputStream.read();
}
};
}
public String getBody() {
return body;
}
}
필터 적용
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
HttpServletRequest httpRequest = (HttpServletRequest) request;
HttpServletResponse httpResponse = (HttpServletResponse) response;
RequestWrapper requestWrapper = new RequestWrapper(httpRequest);
chain.doFilter(requestWrapper, httpResponse);
}
하지만 로그를 찍어보니 body는 공백으로 나왔다
한참동안 이 방법으로 해결하기 위해서 수많은 삽질을 했다 😂
두 번째 시도 : returning = "returnObj" 사용해보기 (안될 것 같긴 했음..)
다른 예시들을 찾아보니 returning = "returnObj"를 사용하여 응답객체를 받아와서 출력하도록 했다
그래서 이 방법으로 응답객체를 출력하기 위해서 시도해봤다
(하지만 그 예시는 @AfterReturning이긴 했다..ㅎㅎ)
(그래도 @Around도 실행 전후에 발생시키는 거니까 응답객체를 사용할 수 있지 않을까하는 일말의 희망으로 사용해봤다.,.)
@Around("userAdminController() || commentAdminController()", returning = "returnObj")
public Object logging(ProceedingJoinPoint joinPoint, Object returnObj) throws Throwable {@Around("userAdminController() || commentAdminController()")
public Object logging(ProceedingJoinPoint joinPoint, @Return("returnObj") Object returnObj) throws Throwable
하지만 인텔리제이에서 빨간줄이 뜨면서 실행할 수 없었다..ㅎㅎ
자세하게 이해하지 못하고 이것저것 끌어서 사용하려니 이런 불상사가 발생한 것이다!
하지만 이것 저것 해봐도 계속 실패했기에 이런거라도 시도해보고 싶었다..
해결 : joinPoint.proceed()의 return 객체로 조회하기
여러번의 시도를 해봤지만 응답객체의 바디값은 나오지 않았고.. 시도했던 이상한 중구난방 클래스들과 메서드들을 모두 지우고 처음부터 다시 찾아보기로 마음을 잡았다
사실 저 첫 번째 시도때 사용했던 코드들은 이해가 잘 되지 않았다 (gpt에게 냅다 물어봐서 얻은 코드이기 때문..)
이걸 쓰면서도 이게 뭔지도 모르고 자꾸 에러나고 하라는대로 하면서 계속 삽질을 했기 때문이다
다시 구글링을 열심히 하면서 찾아본 결과!!
// 메서드 실행
Object result = joinPoint.proceed();
이 result객체가 메서드를 실행한 이후의 응답 객체라는 것이다!!!!
엥?? 그러면 그냥
// 메서드 실행
Object result = joinPoint.proceed();
// 메서드 실행 후
LocalDateTime responseTime = LocalDateTime.now();
String responseBody = getResponseBody(result);
이러면 되는거 아닌가?
실행결과 responseBody값이 드디어 나와 주었다!!😳❤️❤️🥳🩷
API 로깅 전체 코드
LogAspect
@Aspect
@Slf4j
@Component
@RequiredArgsConstructor
public class LogAspect {
@Pointcut("execution(* org.example.expert.domain.user.controller.UserAdminController.changeUserRole(..))")
public void userAdminController() {
}
@Pointcut("execution(* org.example.expert.domain.comment.controller.CommentAdminController.CommentAdminController(..))")
public void commentAdminController() {
}
@Around("userAdminController() || commentAdminController()")
public Object logging(ProceedingJoinPoint joinPoint) throws Throwable {
// 메서드 실행 전
Class clazz = joinPoint.getTarget().getClass();
Logger logger = LoggerFactory.getLogger(clazz);
HttpServletRequest request = ((ServletRequestAttributes) Objects.requireNonNull(RequestContextHolder.getRequestAttributes())).getRequest();
HttpServletResponse response = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getResponse();
Long userId = (Long) request.getAttribute("userId");
LocalDateTime requestTime = LocalDateTime.now();
String requestBody = getRequestBody(request);
Map<String, Object> params = new HashMap<>();
try{
String decodedURL = URLDecoder.decode(request.getRequestURI(), "UTF-8");
params.put("userId", userId);
params.put("requestTime", requestTime);
params.put("requestUrl", decodedURL);
params.put("requestBody", requestBody);
}catch (Exception e) {
logger.error("LoggerAspect error", e);
}
log.info("Request - User : {} | Time : {} | Url : {} | Body : {}",
params.get("userId"),
params.get("requestTime"),
params.get("requestUrl"),
params.get("requestBody"));
// 메서드 실행
Object result = joinPoint.proceed();
// 메서드 실행 후
LocalDateTime responseTime = LocalDateTime.now();
String responseBody = getResponseBody(result);
params.put("responseTime", responseTime);
params.put("responseBody", responseBody);
log.info("Response - User : {} | Time : {} | Url : {} | Body : {}",
params.get("userId"),
params.get("responseTime"),
params.get("requestUrl"),
params.get("responseBody"));
return result;
}
private static String getResponseBody(Object result) {
ObjectMapper objectMapper = new ObjectMapper();
JsonNode resultNode = objectMapper.valueToTree(result);
JsonNode bodyNode = resultNode.path("body");
return bodyNode.toString();
}
public String getRequestBody(HttpServletRequest request) throws IOException {
ObjectMapper objectMapper = new ObjectMapper();
return objectMapper.readTree(request.getInputStream()).toString();
}
}
Filter
@RequiredArgsConstructor
public class JwtFilter implements Filter {
private final JwtUtil jwtUtil;
@Override
public void init(FilterConfig filterConfig) throws ServletException {
Filter.super.init(filterConfig);
}
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
HttpServletRequest httpRequest = (HttpServletRequest) request;
HttpServletResponse httpResponse = (HttpServletResponse) response;
request = new RequestWrapper(httpRequest); // 여기서 요청 객체 저장(캐싱)하기
}
느낀점
- 응답 body를 출력하기 위해서 구글링을 하던 도중 내가 원하는 자료가 많이 보이지 않아서 그냥 gpt에게 물어보면서 해결하려 했는데(첫 번째 시도 : RequestWrapper 사용 부분), 무슨 코드인지도 모르는 상태에서 계속 질문하고 답은 안되고 뱅글뱅글 반복하면서 시간을 너무 허비한 것 같았다..
- 사실 gpt를 사용해서 코드를 짜는 걸 별로 좋아하지 않는데 (내가 짠 코드도 아니고 이게 뭔지도 모르면서 쓰는 것도 찝찝하고 감당이 안되서.. ) 역시 직접적인 문제해결은 내가 일단 이해하고 뭔지 안 다음에 되는 것 같다는 생각이 들었다
- Object result = joinPoint.proceed();이것만 잠시 생각해 봐도 금방 해결할 수 있는 문제를 오히려 gpt를 사용하면서 더 헛수고를 하게 된 것이다..!!!
- 지금 단계에서는 역시 내가 감당하고 이해할 수 있는 코드만 만들고 gpt를 사용한 문제해결을 최대한 지양해야겠다는 생각이 더 들게 됐다
결론 : 문제 해결을 구글링이나 자료보고 생각해보고 하기!