안녕하세요. 오늘은 커넥션 누수의 대해서 알아 보려고 합니다. 제가 커넥션 누수에 대해서 작성을 하게 된 이유는 프로젝트를 진행 하면서 과도하게 CPU을 사용하는 현상이 발생을 했는데요. 로그를 확인 해도 정말 알 수 가 없었고 서버가 중단 될 지경까지 가는 아찔한 순간이 있었는데요. 해당 프로젝트는 외부에서 진행 했었던 프로젝트인 만큼 알고 있는 정보도 많지 않아 정말로 이유를 찾기 힘들었지만 원인을 찾는 과정을 하나씩 기록하며 후에 빠르게 대처하기 위해 작성을 하게 되었습니다.
우선 아래와 같이 해당 서버의 CPU사용률이 굉~장히 높은 현상이 발생했습니다. 무려 각 CPU가 100% 힘으로 계속 동작하고 있었습니다.
정말 놀라웠습니다..!!! 이런건 지금까지 본 적이 없었기 때문이었습니다.
그럼 우선 문제를 파악하기 위해 로그를 확인 했는데 로그에는 크게 문제되는 부분이 없었습니다. 여전히 CPU는 활발하게 사용중이 었기 때문에 당장 문제 해결이 필요 했기 때문에 급하게 Restart 버튼을 눌러 해결을 했습니다.
그럼 무엇이 문제일까... 로그를 확인하던 중에 이상한게 보였습니다. 아래의 로그는 Restart 하고 후에 확인한 로그인데 빨간색 표시에 HikariPool2의 Connection 하나가 active 상태로 계속 유지되는 것이 었습니다.
여기서 HikariPool이 무엇인지 모르시는 분들을 위해 간략하게 설명하고 넘어가겠습니다.
💡HikariCP란
Java 기반 애플리케이션에서 사용되는 고성능 JDBC 커넥션 풀 라이브러리 입니다. 주로 데이터베이스와의 연결을 효율적으로 관리하여 애플리케이션 성능을 향상시키는 데 사용됩니다.
- 고속 연결 풀링
- HikariCP는 빠른 커넥션 풀 성능을 제공합니다. 테스트 결과에 따르면 대부분의 상황에서 가장 빠른 커넥션 풀로 평가받고 있습니다.
- 경량화 설계
- 단순하고 가벼운 구조로 설계되어, 성능을 저하시키는 부가적인 기능을 최소화했습니다.
- 높은 안정성
- 데이터베이스 연결 누수 감지, 자동 복구 기능 등이 있어 안정적으로 연결을 관리합니다.
- 저비용 유지 관리
- 효율적인 리소스 사용으로 메모리 및 CPU 사용량이 적습니다.
아래는 벤치 마크 결과를 보여주는 사진인데 뛰어난 성능을 보여주는 것을 확인 할 수 있습니다.
HikariDataSource를 확인 해 보는 것도 재밌습니다.
위에 있던 Pool stats은 크게 total, active, idle, wating을 가지고 있습니다.
total : 전체 커넥션 커넥션
active : 현재 사용 중인 커넥션
idle : 현재 사용하지 않고 대기 중인 커넥션
wating : 대기중인 커넥션
자 그러면 대략적인 HikariCP에 대한 설명은 끝났고 커넥션을 반환하지 않고 문제를 일으키는 active 커넥션을 찾아야 합니 다. 즉 Connection leak(누수)가 의심되는 포인트를 찾아야겠죠?
흔히 아래와 같이 작성을 많이 하실 겁니다. 물론 value값은 상황에 따라 다를 것입니다.
spring:
datasource:
hikari:
jdbc-url: jdbc:mysql://localhost:3306/mydb
username: root
password: yourpassword
maximum-pool-size: 10
minimum-idle: 5
connection-timeout: 30000
idle-timeout: 600000
max-lifetime: 1800000
pool-name: MyHikariPool
maximum-pool-size | 커넥션 풀이 가질 수 있는 최대 Connection 개수 |
coonection-timeout | HikariCP에 Connection을 요청하고 대기하는 시간 |
minimum-idle | Pool에서 유지되는 최소한의 유휴 Connection 개수 |
idel-timeout | 유휴 상태로 있을 수 있는 시간 |
max-lifetime | 커넥션이 생성된 후 존재 할 수 있 는 시간 |
leak-detection-threshold | 누수 판별시간 |
하지만 저는 여기서 하나의 옵션을 추가로 넣어 주었습니다. "leak-detection-threshold" 해당 옵션은 누수 판별 시간을 초과 하는 경우 warn등급 로그를 stacktrace 형태로 출력하는 기능을 제공해주는 옵션입니다. 해당 옵션을 사용한다면 커넥션 누수가 발생한 포인트 지점을 알 수 가 있고 그부분을 추적하다 보면 왜 해당 누수가 발생했는지 원인을 알 수 있을 것입니다.
spring:
datasource:
hikari:
jdbc-url: jdbc:mysql://localhost:3306/mydb
username: root
password: yourpassword
maximum-pool-size: 10
minimum-idle: 5
connection-timeout: 30000
idle-timeout: 600000
max-lifetime: 1800000
leak-detection-threshold: 2000 # 누수 판별 시간
pool-name: MyHikariPool
leak-detection-threshold | 누수 판별시간 |
해당 옵션을 사용한 결과를 보면 Warn등급의 Connection leak detacted 가 로깅되는 것을 확인 할 수가 있고 사진에는 보이지 않지만 어느 곳에 누수가 발생했는지 라인을 찍어 상세하게 보여주는 곳을 알 수 있습니다.
Connection leak detection triggered for software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@df341a2 on thread http-nio-9500-exec-6, stack trace follows
java.lang.Exception: Apparent connection leak detected
해당 프로젝트에서는 확인 결과 특정 로직에서 무한루프가 돌고있었습니다.
처음 의심이 들었던 포인트는 커넥션 누수가 발생 한것을 알겠는데 왜? cpu를 과도하게 사용하고 있을까? 의심이 들었습니다. 원인은 커넥션을 들고 있는채로 무한루프를 돌으니 계속 커넥션은 active 상태를 유지하고 로직을 계속 끝없이 처리하기 위해 cpu를 사용하는 것이 었습니다...
해당 로직은 수정하고 배포를 하니 그 후로는 해당 문제는 발생하지 않았습니다. 해당 문제는 특정 파라미터에서만 발생을 하는 케이스였는데 그러다 보니 더욱 발견이 어려웠던 문제였던것 같습니다. 그러면서 그원인을 파악하기 위해 많은 공부를 하게 되었던 좋은 경험? 이 었던 것 같습니다.
https://github.com/brettwooldridge/HikariCP-benchmar
'Spring boot' 카테고리의 다른 글
[Spring-Boot] SecureRandom 난수 생성시 Freeze 문제 (0) | 2024.07.18 |
---|---|
[Spring-boot] Mattermost Bot 사용 (0) | 2024.04.24 |
Spring-boot Enum으로 Request,Response 받기 (0) | 2022.12.19 |
Spring boot - Transaction Propagation (1) | 2022.07.15 |
spring boot - 트랜잭션 (0) | 2022.07.01 |