HikariCP 커넥션 누수 해결기 (Session wait

HikariCP 커넥션 누수 해결기 (Session wait_timeout 적용!)

아래의 에러가 뜨면서 커넥션 연결이 실패하는 이슈가 발생했다.

the last packet successfully received from the server was 30,035 milliseconds ago.

조금더 로그를 올라가보니 이런 경고가 뜨고있었다. 아래와 같이 각 커넥션으로 연결을 시도하다가 모두 실패했다.

2023-04-18 08:01:12.345  WARN 20 --- [nio-8080-exec-9] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@1d5d809b (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.346  WARN 20 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@656228eb (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.346  WARN 20 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@1ee6e7a8 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.347  WARN 20 --- [nio-8080-exec-9] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@100d934e (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.347  WARN 20 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@316d65af (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.347  WARN 20 --- [nio-8080-exec-9] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@5a179137 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.348  WARN 20 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@4cf3ac6d (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.348  WARN 20 --- [nio-8080-exec-9] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@2bbf9bb6 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.348  WARN 20 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@38a2e068 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. 
2023-04-18 08:01:12.349  WARN 20 --- [nio-8080-exec-9] com.zaxxer.hikari.pool.PoolBase          : HikariPool-3 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@1ed2242a (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.

원인

원인은 이미 예상했듯 커넥션 누수다.

Application의 HikariCP의 maxTimeOut으로 인해 커넥션 연결을 끊기도 전에 MySQL에서 wait_timeout으로 인해 연결을 끊어버리면 위와 같이 커넥션 누수가 발생한다.

HikariCP와 Tomcat-dbcp 철학이 달라서 발생한 문제라고 한다.
- HikariCP는 Tomcat-dbcp와 달리 사용하지 않는 Connection을 빠르게 회수하도록 설계
- Tomcat-dbcp는 지속적으로 DB에 Validation Query를 보내서 커넥션이 끊어지지 않도록 설계

HikariCP

아래는 PoolBase.isConnectionAlive() 메서드이다.

HikariConfig의 maxLifeTime이 끝나면 커넥션 풀에서 해당 커넥션을 종료 후 리소스(메모리)도 해제한다. 그리고 새로운 커넥션 객체를 생성해서 커넥션 풀에 추가한다.

중요한 점은 wait_timeout으로 인해 DBMS에서 이미 커넥션을 닫았다면 HikariCP는 어떤 행위도 할 수 없다. 로그만 찍어줄 뿐이다.

즉, DBMS에서 wait_timeout으로 커넥션을 끊기 전에 HikariCP의 maxLifeTime으로 커넥션을 해제해야 한다.

해결 방법 (알려진 솔루션)

아래는 이 문제를 해결하는 잘 알려진 솔루션이다.

1. maxTimeOut 조정

HikariCP에서는 maxTimeOut을 DB의 wait_timeout보다 2~3초 낮게 설정하는 것을 권장한다.

문제는 현재 MySQL 운영 서버의 wait_timeout이 15초이고, HikariCP의 maxTimeOut의 최솟값이 30초이다.

private void validateNumerics(){
    if(maxLifetime!=0&&maxLifetime<SECONDS.toMillis(30)){
        LOGGER.warn("{} - maxLifetime is less than 30000ms, setting to default {}ms.",poolName,MAX_LIFETIME);
        maxLifetime=MAX_LIFETIME;
    }
    // ... 생략
}

HikariCP는 maxTimeOut을 30초보다 낮게 잡으면 Default인 30분으로 강제로 설정한다.

HikariCP에서 maxTimeOut이 너무 낮으면 성능 저하나 커넥션 끊기는 이슈가 발생을 우려했다고 한다.

결국 해당 부분은 라이브러리를 교체하거나 내부를 뜯어고쳐야 한다. 권장되지 않는 방법이라서 적용하지 않았다.

2. wait_timeout 조정

MySQL 서버의 wait_timeout을 조금 더 높게 수정을 하면 이를 해결할 수 있다.

하지만 개발 운영팀에서는 기존의 PHP 레거시 코드 때문에 wait_timeout을 높이지 못한다는 답변을 받았다.

기존에 존재하는 PHP 프로젝트의 특성상 커넥션을 맺고 커넥션을 닫지 않고 종료되는 일이 너무 많다.
그 경우 빨리 커넥션을 끊지 않으면 성능이 크게 저하되다가 서버가 터질 수 있다고 함

3. autoReconnect 옵션을 설정

HikariCP의 JdbcUrl의 autoReconnect 파라미터를 true로 설정할 수 있다.

단, 해당 부분은 트랜잭션이 진행중일 때 연결이 끊기면 즉시 커밋되는 이슈가 있어서 정합성에 문제가 생겼다.

결국 이 방법도 적용할 수 없었다.

적용한 방법

다음으로 선택한 방법이 세션의 wait_timeout을 설정하는 방법이다.

wait_timeout 설정도 GLOBAL 설정이 있고, SESSION 설정이 있었다.

즉, SpringBoot 앱에서 MySQL 서버로 연결할 때 세션의 wait_timeout을 바꿀 수 있다면 해결할 수 있지 않을까..? 하는 생각이었다.

hikari:
  pool-name: HikariCP
  maximum-pool-size: 10
  connection-timeout: 10000
  validation-timeout: 10000
  max-lifetime: 580000
  # Session wait_timeout 수정
  connection-init-sql: set wait_timeout = 600

spring.datasource.hikari.connection-init-sql 프로퍼티를 사용하면 Connection 객체가 생성될 때 세션 wait_timeout을 수정할 수 있다.

문제가 생긴 프로젝트의 경우 다중 데이터 소스를 사용하고 있어서 아래와 같이 설정할 수 있었다.

if(hikariConfig.getDriverClassName().equals("com.mysql.cj.jdbc.Driver")) {
    long waitTimeOut = TimeUnit.MILLISECONDS.toSeconds(hikariConfig.getMaxLifetime()) + 5;
    hikariConfig.setConnectionInitSql(String.format("SET SESSION wait_timeout = %s", waitTimeOut));
}

세션의 wait_timeout을 HikariPool의 maxLifeTime보다 5초 더 높게 설정했다.

결과적으로 더 이상 커넥션 누수가 발생하지 않았고 maxLifeTime을 늘리라는 경고가 나타나지 않았다. 성공적으로 적용을 완료할 수 있었고 현재도 문제 없이 운영 중이다!

Hibernate @Where 애노테이션이 동작하지 않는 이유! (0)	2023.11.05
Hibernate - QueryPlanCache Memory Leak 해결하기! (0)	2023.06.29
Spring - @Transactional(readOnly = true)을 하면 일어나는 일 (0)	2022.11.04
Spring - Service Layer에서 Storage를 다룰 때 트랜잭션 처리하기! (커넥션, 락 과점유 피하기!) (0)	2022.10.25
Spring Transaction - Propagation(전파 속성) (0)	2022.10.04

Official-Dev. blog