일을 하면서 서버 에러로그에 언제부턴가HikariPool-1 - Connection is not available, request timed out after 3000ms
위와 같은 에러 문구가 특정 주기를 가지고 계속 노출되었다.
일단 여러가지 문제가 있었는데, 먼저 해결된 것부터 써보려고 한다.
HikariCP pool size
일단 내가 개발하는 서비스 특성상 특정 시간대 or CRM으로 푸시알림이 발송된 순간에 트래픽이 몰리는 경향이 있다.
그래서 내가 입사하기 이전부터 서비스에선 hikari cp 권장사항인 maximum-pool-size와 minimum-idle 개수를 다르게 줬었다.
물론 minimumIdle 설정 개수가 더 적었었다.
그렇게 잘 유지되다가 어느날부터 트래픽이 몰리면 이제 유휴에서 maximum개수가 될 때까지 connection pool을 만들게되는데 이 때 만드는 속도보다 커넥션을 더 많이 필요로 하게되면 그때부터 지연 응답이 되면서 해당 에러로그가 집계 되었다.
초창기보다는 트래픽이 어느정도 늘었기 때문에 내가 당시에 HikariCP Docs 를 읽고서 아래 이미지 처럼 쓰여있길래 일단 pool size 개수를 maximum, minimum 개수를 하나로 맞추자고 했었다.
그래서 개선하고 난 뒤에는 에러로그가 해소되었었다!!!
서버가 시작하자마자 바로 엄청난 트래픽이 호출되었을 때
일단 이 부분은 인프라 설정과도 관련이 있을 수 있는데, 톰캣 서버가 시작된 이후에 우린 spring actuator가 제공해주는 /actuator/health
를 통해 AWS ECS에서 헬스체크를 하고있다.
이 때 health check 성공 갯수의 호출 간격이 되게 짧았어서 성공하면 이제 connection pool은 1개씩 애플리케이션이 구동되고 생성되는데, 이 pool size가 다 차지 않았음에도 서비스를 시작하는 경우에도 마찬가지로 같은 에러로그가 나왔었다.
이 부분은 뭐 따로 우리쪽에서 해결할 것이 없이 인프라팀에 요청드려서 health check 간격을 좀 더 늘려서 해달라고 요청을 드렸었고, 이 이후에는 해당 설정 관련으로 에러로그가 따로 나오지는 않았던 것 같다.
아직 해결하지 못한 AWS Aurora Mysql Serverless 설정
이건 계속해서 아직도 발생하고 있다!!!
회사의 DBA분도 같이 계속해서 봐주고계신데, 아무리 생각해도 설정상 문제는 없는데 어떤 특정 시간대에 마구잡이로 위에서 나왔던 에러로그가 무수히 많이 찍혔었다.
처음으로 DB자체를 의심했던 순간이었다.
애초에 serverless로 db를 바꾸면서 갑자기 에러로그가 나오는 것을 보고 혹시나 하면서 우리 팀 내 개발자분들도 전부 DB를 의심했다.
그래서 처음에 DBA분도 aws에 문의를 해봐야겠다고 해서 질문을 드린후 이런 답변이 왔었다.
이전에 설명드린 대로 해당 이슈는 innodb buffer pool resize 과정에서 hash resize가 발생하여 wait/synch/sxlock/innodb/hash_table_lock 대기 이벤트가 발생했고, 이로 인해 고객님의 serverless cluster에서 hash resize 과정이 완료될때 까지 connection 이슈가 지속 되었던 것으로 확인됩니다.
현재 고객님이 사용하시는 serverless cluster는 mysql_aurora.3.06.1 버전을 사용 하시는 것으로 확인됩니다.
Aurora mysql 3.08 버전부터 "확장 또는 축소 이벤트 중에 잠금 해시 테이블의 크기 조정이 길어져 발생하는 재시작 문제"가 해결되어, hash resize로 인한 재시작 및 connection 이슈가 완화된 것으로 확인됩니다. [+]
해당 serverless cluster를 mysql_aurora 3.08 이상 버전으로의 업그레이드를 고려해 보시는 것을 권해드립니다.
[+] Aurora MySQL 데이터베이스 엔진 업데이트 2024-11-18(버전 3.08.0, MySQL 8.0.39와 호환) - https://docs.aws.amazon.com/ko_kr/AmazonRDS/latest/AuroraMySQLReleaseNotes/AuroraMySQL.Updates.3080.html
고객님께서 aurora mysql의 버전 업그레이드가 상황적으로 어려우시다면, 다음과 같은 사항들을 점검해보시는 것을 권해드립니다.
▼ hash_table_lock 대기 이벤트는 주로 세 가지 이유로 발생할 수 있습니다. [+]
(1). 버퍼 풀의 크기가 너무 작아서 자주 접근하는 페이지를 모두 메모리에 유지할 수 없을 때
(2). 워크로드가 많아서 데이터 페이지가 자주 제거되고 다시 로드될 때
(3). 버퍼 풀에서 페이지를 읽는 중에 오류가 발생할 때 (이는 데이터 손상을 의미할 수 있습니다)
[+] synch/sxlock/innodb/hash_table_locks - https://docs.aws.amazon.com/ko_kr/AmazonRDS/latest/AuroraUserGuide/ams-waits.sx-lock-hash-table-locks.html
현재 고객님의 serverless 클러스터는 minAcu 0.5, maxAcu 45로 설정되어 있는 것으로 확인됩니다. serverless 클러스터는 워크로드 변화에 따라 자동으로 scailing 되는데, 이 과정에서 minAcu과 maxAcu 값, 그리고 실제 워크로드 양에 따라 scailing의 규모가 달라집니다.
많은 워크로드가 갑자기 들어오면 innodb buffer pool의 대규모 resize가 발생하고, 이때 hash resize도 함께 일어나게 됩니다. 따라서 우선적으로 워크로드를 점검해 보시는 것을 권해드립니다.
고객님께서는 performance insight를 사용 중이시므로, minAcu를 2.0 이상으로 올리시는 것을 권장드립니다. 또한, 고객님의 환경에서 테스트를 통해 워크로드 양에 따른 Acu 최적화도 진행해 보시는 것을 권해드립니다. [+]
[+] 클러스터에 대한 최소 Aurora Serverless v2 용량 설정 선택 - https://docs.aws.amazon.com/ko_kr/AmazonRDS/latest/AuroraUserGuide/aurora-serverless-v2.setting-capacity.html#aurora-serverless-v2.viewing.performance-insights
이렇게 그 당시에 답변이 왔었고, 결국에 우리 버전이 3.08 보다 낮은 버전을 사용했었고, 이 때 serverless mysql이 트래픽이 많이 몰리는 순간 스케일 아웃을 진행할 때 innodb buffer pool의 resize가 발생하니까 이 때 순단이 될텐데, 커넥션을 이 당시에 맺을 수 없으니까 애플리케이션 입장에서는 커넥션을 당연히 사용할 수 없는 상황이고 그에 따라서 connection 이슈가 슈루루룩 하고 쌓였던 것이다.
이 때마다 고객들에게 서비스를 제대로 제공하지 못하는 것에 나는 굉장히 조금 아쉬웠었다.
아직도 이 minAcu 라는 값은 회사 내에서 계속 적정 값을 찾아서 튜닝을 하고 있는 중이다.
마무리
결국 서비스를 잘 운영하다가도 이벤트로 트래픽이 확 증가하는 순간에는 미리 예측한 모수정도를 위한 서비스 증설, db 사양 반영을 한다면 어느정도 대응은 가능하겠지만 의도치 않은 or 이벤트를 의도했지만 예상한것보다 더 많이 들어오는 경우는 무조건적으로 이렇게 간헐적인 에러가 나고, 그 에러를 해소하기 위해 별도의 사양 증설은 무조건적으로 필요한 것 같다.
100% 막을 수 있다면 너무 좋겠지만? 이 나름대로 해소하는 재미가 있다고 생각한다.
그리고 이런걸 빠르게 대처하려면 그만큼 다른 피쳐들을 쳐내는것도 물론 중요하겠지만 모니터링을 많이 그리고 꼼꼼히 사소한거여도 사내 메신저에 빠르게 공유하는 습관을 많이 들여야겠다고 생각한다. (그리고 혼자 머리 싸매는것보다 빠르게 공유하여 주변 개발자분들과 같이 해결해보려고 하는 자세를 가지는게 난 더 중요한 것 같다.)
이 에러 무조건적으로 해결하면 블로그를 써야지~ 했는데 끝날 기미가 안보여서 이정도로 먼저 기록해보려고 한다!
번외 : 앞으로 블로그 좀 더 잘쓰고 많이 쓰려고 노력해야겠다. 너무 놀았던것 같다 ㅋㅋㅋㅋ 🔥🔥🔥🔥🔥
'DB' 카테고리의 다른 글
쿼리 속도 개선기 (0) | 2022.08.07 |
---|---|
[DB] 옵티마이저 (0) | 2022.08.05 |