Post

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

Posted Updated
By umbum 4 min read

최근 알 수 없는 이유로 운영 서버에 응답 지연 현상이 발생했었는데요,
특정 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.0X
spring-boot 2.2.11X
spring-boot 2.2.8X
spring-boot 2.2.6X
spring-boot 2.2.5 & tomcat 9.0.33O
spring-boot2.2.5 & spring-webmvc 5.2.5.RELEASEX
spring-boot 2.2.5O
spring-boot 2.2.4O

재현 조건 정리

  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회 정도 연속으로 전송하면, 응답지연 발생

정확한 원인?

대응

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

Java Stack, Spring
This post is licensed under CC BY 4.0 by the author.