getReader() has already been called for this request 에러

상황

• Frontend에서 JWT token을 이용해 내 API 서버에 인증&인가를 요청하는 과정에서 디버깅을 진행하고 있었다. 이는 Spring Security Filter level에서 진행되기에 아래의 code로 request의 Header들과 Body를 CustomAuthorizationFilter에서 한번씩 로깅한 후, Controller로 request를 전달하는 로직을 작성했다.

Enumeration<String> headerNames = request.getHeaderNames();
log.info("Header List");
while (headerNames.hasMoreElements()) {
    String headerName = headerNames.nextElement();
    String headerValue = request.getHeader(headerName);
    log.info(headerName + " : " + headerValue);
}
try (BufferedReader reader = request.getReader()) {
    StringBuilder requestBody = new StringBuilder();
    String line;
    while ((line = reader.readLine()) != null) {
        requestBody.append(line);
    }
    log.info("Request Body : " + requestBody.toString());
} catch (IOException e) {
    log.error("Error reading request body : " + e.getMessage());
}

• 그런데 POST를 제외한 다른 API들은 정상적으로 logging과 controller에서 처리되었으나, POST method는 getReader() has already been called for this request 라는 error와 함께 처리되지 않았다.

원인

• Header와는 달리 POST 방식으로 전달된 "application/json" 타입의 데이터는 Servlet의 Filter에서 처리할때 HttpServletRequest의 InputStream을 통해서 읽어야한다.
• getReader()는 InputStream을 반환하여 request를 읽어내는데 InputStream은 Tomcat에서 두번 다시 읽을 수 없게 막아놨다. (InputStream은 내부적으로 포인터를 사용해 읽은 위치를 기억하게 되는데, 한 번 읽으면 읽은 위치를 되돌릴 수 없는 것 같다. 나의 경우는 이미 Filter에서 다 읽었기에 controller에서는 읽을 데이터가 없다 판단하게 된다.)
• GET method로 넘어오는 정보들은 InputStream으로 들어오지 않는데, 이는 query parameter나 path variable과 같이 URL 방식으로 넘어오는 parameter들은 별도로 보관하고 처리하기 때문이다. 때문에 POST API들만 error가 발생했다.

해결

• HttpServletRequestWrapper를 통해 getInputStream()을 override하여 처음 inputStream을 읽어 저장한 뒤, 다음 부터는 저장된 inputStream을 복제해 전달해줌으로써 다시 읽을 수 있도록 처리하면 된다.
• 나의 경우는 로직 구현에 필요한 코드가 아닌, 단순 디버깅 용도였기에 Frontend와의 디버깅이 해결된 이상 Filter에서 굳이 request를 한번 더 처리할 필요는 없다. 따라서 해당 코드를 삭제해서 해결했다.
• 만약 추후 Servlet의 Filter나 Spring의 Interceptor에서 request를 처리할 일이 있다면, 위와 같이 InputStream을 복제하여 돌려주는 코드를 작성해야겠다.
• 단순 로깅용이라는 생각에 Stack Overflow에 돌아다니는 request body 찍는 코드를 아무렇게나 갖다 쓴 내 자신을 반성하게 되었다.

참고

https://meetup.nhncloud.com/posts/44
https://aljjabaegi.tistory.com/683