본문 바로가기

Java/Spring

StreamingResponseBody 사용시 주의점

파일 다운로드 API 기능을 개발하는 과정에서 삽질한 경험를 공유드립니다 ㅎ

목적​
Streaming 형태의 Response로 제공하고 싶었습니다.
그래서 구글링해보니 Spring에선 아래 3가지 Response를 제공합니다.
참고 : Spring 4.2 이상
이 중 StreamingResponseBody는 비정형화된 Byte 응답을 Streaming형태로 줄 때 사용합니다.
StreamingResponseBody를 이용해 Controller와 Service는 아래와 같이 구현했습니다.
Controller
 

@GetMapping("/sample")
public StreamingResponseBody downloadAsync(@RequestParam("id") String id) throws Exception {
(...로직 생략 및 간소화...)


ListenableFuture<StreamingResponseBody> result = sampleService.asyncDownloadFromHdfs(id);
return result.get(5, TimeUnit.MINUTES);

}​

Service
 

@Override
@Async("sampleExecutor")
public ListenableFuture<StreamingResponseBody> asyncDownloadFromHdfs(long id) {
return this.downloadFromHdfsAndCopyStream(id);
}​

private ListenableFuture<StreamingResponseBody> downloadFromHdfsAndCopyStream(long id) {
InputStream inputStream = this.downloadFromHdfs(id);

StreamingResponseBody streamingResponseBody = outputStream -> {
FileCopyUtils.copy(inputStream, outputStream);
};
return new AsyncResult<>(streamingResponseBody);
}​

불필요한 로직 및 코드를 간소화하면 InputStream으로 읽은 파일 정보를 OutputStream으로 복사하여
Streaming으로 리턴하는 간단한 로직입니다.
문제
정상적으로 파일을 다운로드하는 경우엔 이슈가 없습니다.
하지만 Timeout이나 사용자가 다운로드를 취소하는 이벤트를 발생시켰을 때 문제가 발생합니다.
그렇다고 항상 다운로드 받는 도중에 취소한다고 발생하는 것은 아니며
IOException이 아닌 NullPointException이 발생하면 문제가 됩니다.
NullPointException이 발생하면 두 가지 문제가 발생합니다.
1. 이미 취소된 Response인데도 Connection 유지 (1분후 종료)
2. 에러 직후 다음 요청시 이미 Response는 닫혀있음
1. 이미 취소된 Response인데도 Connection 유지 (1분후 종료)
이 경우 tomcat connection timeout 문제로 기본 값이 60초라 시간을 조절하여 해결했습니다.
다른 에러땐 즉시 끊겨서 이슈가 없는데 NullPointException이 발생하면 connection이 timeout 시간만큼 유지됩니다.
springboot embedded tomcat이면 application 프로퍼티에서 server.connection-timeout 값 설정
일반 tomcat이면 server.xml에서 timeout 설정
2. 에러 직후 다음 요청시 이미 Response는 닫혀있음
우선 디버깅 내용을 보겠습니다.
원인 파악
에러 핸들링을 하지 않아서 발생한 문제일까 싶어서 처음엔 서비스 로직에 try ~ catch와 CallableProcessingInterceptor를 등록했었습니다.
CallableProcessingInterceptor는 비동기처리동안 흐름을 관리할 수 있도록 도와주는 객체로 handleTimeout 메서드를 통해 timeout 이후 로직을 처리할 수 있습니다.
하지만.. catch 혹은 handleTimeout을 통해 response를 직접 close, flush 하려고 해도 이미 Response는 commit된 상태로 정상적으로 처리되어 있었습니다.
NPE 에러 발생 후 응답이 제대로 종료되지 않는 것 같아서 먼저 Response의 상태를 살펴보니...
정상적으로 처리되고 다시 요청하면 coyoteResponse의 commit의 상태가 false인데 
NPE가 발생후 다시 요청하면 아래와 같이 false가 아닌 true가 나타나게됩니다.

혹시 coyoteResponse만 해시값이 항상 일정한데 이 문제일까? 싶었으나 상관 없었습니다.
왜 NPE일때만 commit이 제대로 관리되지 않을까?
에러 스택을 자세히 보겠습니다.
 java.lang.NullPointerException
at org.apache.coyote.http11.Http11OutputBuffer$SocketOutputBuffer.doWrite(Http11OutputBuffer.java:644)
at org.apache.coyote.http11.filters.ChunkedOutputFilter.doWrite(ChunkedOutputFilter.java:121)
at org.apache.coyote.http11.Http11OutputBuffer.doWrite(Http11OutputBuffer.java:235)
at org.apache.coyote.Response.doWrite(Response.java:541)
at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:351)
at org.apache.catalina.connector.OutputBuffer.flushByteBuffer(OutputBuffer.java:815)
at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:310)
at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:263)
at org.apache.catalina.connector.CoyoteOutputStream.close(CoyoteOutputStream.java:157)
at org.springframework.util.FileCopyUtils.copy(FileCopyUtils.java:122)
at com.sample.service.SampleService.lambda$downloadFromHdfsAndCopyStream$0(SampleService.java:93)
at org.springframework.web.servlet.mvc.method.annotation.StreamingResponseBodyReturnValueHandler$StreamingResponseBodyTask.call(StreamingResponseBodyReturnValueHandler.java:106)
at org.springframework.web.servlet.mvc.method.annotation.StreamingResponseBodyReturnValueHandler$StreamingResponseBodyTask.call(StreamingResponseBodyReturnValueHandler.java:93)
at org.springframework.web.context.request.async.WebAsyncManager$4.run(WebAsyncManager.java:317)
... 생략 ...
- 마지막 Http11OutputBuffer의 doWrite에서 에러가 발생했습니다. (혹은 commit 메서드에서도 발생합니다)
내부코드는 대략 아래와 같습니다.
 
public int doWrite(ByteBuffer chunk) throws IOException {
try {
int len = chunk.remaining();
Http11OutputBuffer.this.socketWrapper.write(Http11OutputBuffer.this.isBlocking(), chunk);
len -= chunk.remaining();
Http11OutputBuffer.this.byteCount += (long)len;
return len;
} catch (IOException var3) {
Http11OutputBuffer.this.response.action(ActionCode.CLOSE_NOW, var3);
throw var3;
}
}​

- this.socketWrapper가 Null이되어 NPE가 발생한 것인데요~
로직을 자세히보면 try ~ catch로 묶여있으나 IOException만 따로 처리하고 있습니다.
IOException이 발생하면 
 
case CLOSE_NOW:
this.setSwallowResponse();
if (param instanceof Throwable) {
this.setErrorState(ErrorState.CLOSE_NOW, (Throwable)param);
} else {
this.setErrorState(ErrorState.CLOSE_NOW, (Throwable)null);
}
break;​
내부적으로 response http status와 비동기 에러 처리와 같이 후속 처리를 진행하고 다음 request에도 정상적으로 처리가 되지만
NPE가 발생하면 catch되지 않고 throw되어 coyoteResponse는 에러에 대한 후속처리 없이 끝나게 됩니다. 
(아무래도 이 부분이 문제가 되는 것 같습니다...)
톰캣 내부 로직에서 처리되다보니 제가 어떻게 컨트롤할 방법이 없었습니다.
그렇다면 답은 버전 업그레이드일 것 같아서 찾아보니...
- https://bz.apache.org/bugzilla/show_bug.cgi?id=61524
톰캣 8.5.x, 9.x 모두 발생하는 것 같습니다. 아직 해당 케이스를 재현하지 못해 해결이 안된 모양입니다 ㅜㅜ
해결은 어떻게?
coyoteResponse가 문제라 톰캣 옵션으로 조절할 수 있지 않을까 싶어서 구글링해보니
톰캣의 RECYCLE_FACADES 옵션이 있었습니다. 기본 값은 false인데 true 로하면 매번 요청시마다 새로 객체를 생성하게 됩니다.
- https://tomcat.apache.org/tomcat-8.5-doc/config/systemprops.html
- NBP 외부 ncloud 가이드는 true를 권장하고 있었습니다.
   - https://docs.ncloud.com/ko/security/security-9-3.html
- Embedded Tomcat
 
public static void main(String[] args) {
System.setProperty("org.apache.catalina.connector.RECYCLE_FACADES", "true");
SpringApplication.run(SampleApplication.class, args);
}​
- 일반 톰캣 : -Dorg.apache.catalina.connector.RECYCLE_FACADES=true
- https://stackoverflow.com/questions/40798502/where-can-i-find-the-org-apache-catalina-connector-recycle-facades-system-proper?noredirect=1&lq=1
옵션 true로 변경하니 에러가 해결된 것을 확인했습니다!
마치며...
StreamingResponseBody는 쓰기 편하고 간소해서 좋았는데
진행 도중 NPE가 발생하면 의도치 않은 버그가 발생할 수 있습니다.
그 땐 org.apache.catalina.connector.RECYCLE_FACADES을 true로 주시면 해결됩니다.
마지막으로.. Controller의 비동기리턴을 하게 되면 WebAsyncManager가 관리하게됩니다.
spring.mvc.async.request-timeout 혹은  + WebMvcConfigurer를 통해 timeout 및 ThreadPool 설정을 할 수 있습니다.
 

@Bean
public org.springframework.web.servlet.config.annotation.WebMvcConfigurer configurer(){
return new WebMvcConfigurerAdapter() {
@Override
public void configureAsyncSupport(AsyncSupportConfigurer configurer) {
ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
executor.setCorePoolSize(10);
executor.setMaxPoolSize(10);
executor.setQueueCapacity(25);
executor.setThreadNamePrefix("sample-down-");
executor.initialize();
configurer.setTaskExecutor(executor);
}
};
}​

혹시 잘못된 점 있으면 댓글 부탁드립니다 ㅎ