API 요청/응답을 로깅하는 필터를 붙였다. 로그는 잘 남았는데, 그 뒤로 컨트롤러가 요청 바디를 못 읽는다며 빈 값으로 처리되기 시작했다.
요청 바디 스트림은 한 번만 읽힌다
HTTP 요청 바디는 InputStream이라 기본적으로 한 번 읽으면 끝이다. 로깅 필터에서 바디를 읽어 로그로 남기는 순간 스트림이 소진됐고, 그 뒤 컨트롤러가 다시 읽으려 하니 남은 게 없었다. 로그를 위해 데이터를 먼저 빨아들여 버린 셈이다.
읽은 내용을 캐싱해서 다시 읽게
스프링이 제공하는 ContentCachingRequestWrapper로 요청을 감쌌다. 이 래퍼는 한 번 읽은 바디를 내부에 저장해 두기 때문에, 필터가 로깅으로 읽어도 컨트롤러가 다시 온전히 읽을 수 있다.
var wrapped = new ContentCachingRequestWrapper(request);
chain.doFilter(wrapped, response);
byte[] body = wrapped.getContentAsByteArray(); // 처리 후 로깅
주의할 건 캐싱된 바디는 처리가 끝난 뒤에야 채워진다는 점이라, 로깅은 doFilter 다음에 해야 했다. 스트림은 한 번뿐이라는 기본을 잊고 있었던 실수였다.