spring-webmvc 5.2.4 이하(springboot 2.2.5 이하) 버전에서 발생하는 응답지연 현상

 

최근 알 수 없는 이유로 운영 서버에 응답 지연 현상이 발생했었는데요,
특정 request 수신 시 spring-webmvc 5.2.4 이하 버전에서 발생하는 것으로 밝혀졌습니다.
-- 응답지연 현상 분석 결과, 재현 방안, 대응책 공유

 

상황

• 11/27 보안 스캐닝 진행 중 API-A 서버에서 응답지연 발생
• 보안스캐닝 중지 후에도 응답지연 지속됨
• 재시작 후 정상화
• 9/8에 발생했던 API-B 서버 응답지연과 양상이 비슷함

 

응답지연 발생 시점 PINPOINT log

• 보안스캐닝 패킷이 인입된 시간은 16:26 부근
• 응답지연이 발생하기 시작한 시간은 16:33
• api-a 재시작 16:54

 

 

보안스캐닝 패킷 일부

 

재현

beta api-a 테스트

• beta api-a 서버에 ngrinder로 부하 주면서 보안스캐닝으로 인입된 패킷 중 장애 원인으로 의심되는 패킷들 전송하며 반응 관찰
• @RequestBody로 파라미터를 받는 Controller 주소에 ( POST | PUT ) + multipart/form-data 형식으로 패킷을 전송하면, 일정 시간 후(약 1.5시간) 응답지연 발생
  • postman으로 연속으로 약 10회 전송

alpha api-b 테스트

• api-a 테스트와 동일하게, @RequestBody를 사용하는 컨트롤러에 ( POST | PUT ) + multipart/form-data 형식으로 패킷을 10번 정도 전송했더니 응답지연 발생
• TPS 그래프가 급감하는 시점이 form-data 패킷 주입하는 시점과 일치

 

특징

• 시작 후 문제 패킷을 주입해도 바로 응답지연이 발생하지 않는 경우가 있는데, 해소되지 않는 데미지가 점차 쌓여야 지연이 발생하는 것으로 보임.
• 뒤로 갈 수록 지연 시간이 증가하고 있지만, 요청 횟수는 거의 동일하다
• 즉, 앞에서 한 번 밀리기 시작하면 같은 요청 강도에서 점점 더 지연시간이 증가한다.
• 재시작 전 까지 해소되지 않는다.
• 지연 발생하는 시점부터 Active Request가 max치가 된다. 그 전에는 0에 가깝다.
• PINPOINT 프로파일링 결과에 따르면 doPost()에서 대부분의 시간을 사용하고 있다. => Spring 자체 문제 의심

 

버전 테스트

버전	지연 발생 여부
spring-boot 2.4.0	X
spring-boot 2.2.11	X
spring-boot 2.2.8	X
spring-boot 2.2.6	X
spring-boot 2.2.5 & tomcat 9.0.33	O
spring-boot 2.2.5 & spring-webmvc 5.2.5.RELEASE	X
spring-boot 2.2.5	O
spring-boot 2.2.4	O

재현 조건 정리

1. org.springframework:spring-webmvc(및 관련 모듈) 5.2.4 이하 버전 (lower bound는 확인하지 않았지만 5.2.0~5.2.4로 추정)
2. 시작 후 최소 1.5시간 지난 후에
3. @RequestBody로 파라미터를 받는 Controller 주소에 ( POST | PUT ) + multipart/form-data 형식으로 패킷을 10회 정도 연속으로 전송하면, 응답지연 발생

 

정확한 원인?

• spring-web 5.2.5 패치 노트를 보니 LRUCache 관련 performance degradation 이슈 및 memory leak 이슈가 있었음.
• https://github.com/spring-projects/spring-framework/issues/24671
• https://github.com/spring-projects/spring-framework/issues/24886
• https://github.com/spring-projects/spring-framework/issues/24767
• jvmtop 으로 프로파일링 해본 결과, ....springframework.util.MimeTypeUtils$ConcurrentLruCach()는 평소 점유율이 보이지 않을 정도로 낮지만, 지연이 발생하는 시점 부터 CPU 점유율이 급증함!

대응

org.springframework:spring-webmvc 버전 5.2.6 이상으로 업그레이드