DEXTUploadNJ 대용량 파일업로드 라이브러리 에러 원인 찾기

에러로그

o.e.c.s.e.ExceptionHandlerAdvice: handleException

org.springframework.web.multipart.MultipartException: Could not parse multipart request.; nested exception is devpia.dextuploadnj.DEXTUploadNJDataParseFailedException: PRODUCT = DEXTUploadNJ

[DEXTNJ: EntityBodyReader.loadCacheStrictly] The request is end(left = 32059, total = 32059)!

at devpia.dextuploadnj.support.spring.DEXTUploadNJMultipartResolver.resolveMultipart(DEXTUploadNJMultipartResolver.java:150)

 

프로젝트에서 대용량파일업로드를 위해 해당 라이브러리를 사용중이다. 

파일업로드 기능은 원래 잘 됐는데 

새로운 기능으로 업데이트하려고 개발하다가 갑자기 파일 업로드가 안되는 것이었다.

처음에는 코드상으로 오류가 있나 싶어서 데이터를 보내고 받는 부분을 집중적으로 파악했다.

 

하지만 아무리 해도 위의 에러를 벗어날 수 없어서 

예전 코드로 롤백을 시켰는데도 여전히 동일 에러가 났다.. 대환장;

 

여러 ai한테 물어봐도 해결이 안돼서 더 자세한 로그를 찍어보기 위해 

spring의 로그레벨을 조정하던 중 문제의 원인을 발견했다. 바로 그 자세한 로그 자체가 원인이었다.

 

---

로그레벨과 inputStream의 상관관계(feat.dextuploadnj)

 

InputStream

InputStream은 우리가 post, get 등을 사용해서 서버로 요청을 보낼 때,

서버에서 그 요청을 읽어오기 위한 통로라고 할 수 있다.

이 InputStream은 몇 가지 특징이 있는데

• 읽기만 가능하며 뒤로 되돌릴 수가 없다.
• 처음부터 끝까지 순서대로만 읽을수 있다
• 읽은 데이터는 메모리에서 사라진다 (포인터가끝으로 이동)

DEXTUploadNJ

DEXTUploadNJ는 대용량 파일 업로드(shp같은 레이어 파일) 를 위한 외부 라이브러리이다.

이 라이브러리는 매우 엄격한 규칙을 가지고 있는데,

서버로 들어오는 http 요청 전체를 분석할 때, 스트림 전체를 처음부터 끝까지 자기가 직접 읽으려고 한다.

중간에 조금이라도 읽은 흔적이 있거나 유실된 데이터가 있다면 에러를 던진다.

log level

스프링의 application.yml이나 properties 파일에서 다음과 같이 로그의 레벨을 설정할 수 있다.

logging:
  level:
     org.springframework: DEBUG
     devpia.dextuploadnj: TRACE

 

레벨의 정도는 INFO (default), WARN, DEBUG, TRACE, ERROR 등이 있다.

레벨을 명시하지 않았을 때의 기본값은 INFO로, INFO, WARN, ERROR 정도만 출력된다.

 

그러나 DEBUG로 설정한다면 어떻게될까?

INFO와의 가장 큰 차이는 바로 로깅을 위해 요청 본문을 읽어버린다는 점이다.

특히 org.springframework:를 DEBUG로 설정하면 스프링의 모든 컴포넌트(필터, 컨버터) 가 컨트롤러에 진입하기도 전에 inputstream을 읽어버리는 문제가 발생한다.

 

자, 그러면 다시 InputStream의 세 번째 특징에 주목해보자.

분명히 한 번 읽으면 끝이라고 했다.

그러면 DEBUG레벨로 설정했을 때, 단순 로그를 위해 요청을 읽어서 소모해버린다는건데,

 

이를 방지하기 위해 스프링 프레임워크는 내부적으로 ContentCachingRequestWrapper 등을 사용해서 요청을 캐싱한다. 로그를 위해 스트림를 읽어도 저장해놓았기 때문에 데이터가 유실되지 않는다.

 

반면, DEXTUploadNJ는 모든 것을 자기가 통제하려고 하기 때문에 스프링과 별개로 자기만의 독자적인 파싱 로직을 가지고 직접 원시데이터를 읽으려 한다. 즉, 별도의 캐싱이 없다는 것이다.

 

그렇기때문에, DEXTUploadNJ 를 사용하는 환경에서, 로깅레벨을 DEBUG로 설정하면

캐시되지 않은 inputStream을 스프링 필터 등이 먼저 읽어버려

DEXTUploadNJ 가 예외를 던져버리는 문제상황이 발생하게 된다…

 

이를 해결하려면

로깅레벨을 INFO로 설정하던지

아니면 별도의 캐싱과정을 추가하던지

방법을 써야한다…

 

---

아무튼, 그래서 자꾸 읽을 body가 없다,, 읽다가 멈췄다 그런 에러가 떴던 거였는데

이 동작과정을 모르면 알아채기 힘든 부분이었고

단순 로그만 찍는줄 알았는데 요청을 읽고 캐싱을 하고 이런 내부적인 과정이 있다는 걸 알게되었다..