본문 바로가기

카테고리 없음

[Error] Failed to validate connection org.mariadb.jdbc.Connection@* ((conn=*) Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.

 

에러 로그

[2024-05-20 00:27:15:244642169]  INFO  1 --- [nio-8080-exec-1] [221.133.55.106] c.d.e.common.aop.LoggingAspect           : [IP: 221.133.55.106] Request Start - Method: ProjectController.createProject
[2024-05-20 00:27:20:244647175]  WARN  1 --- [nio-8080-exec-1] [221.133.55.106] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.Connection@731f5def ((conn=1414) Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
[2024-05-20 00:27:25:244652182]  WARN  1 --- [nio-8080-exec-1] [221.133.55.106] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.Connection@510f71b4 ((conn=1415) Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
[2024-05-20 00:27:30:244657188]  WARN  1 --- [nio-8080-exec-1] [221.133.55.106] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.Connection@7a458a8a ((conn=1416) Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
[2024-05-20 00:27:35:244662190]  WARN  1 --- [nio-8080-exec-1] [221.133.55.106] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.Connection@40f9f5da ((conn=1417) Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
[2024-05-20 00:27:40:244667193]  WARN  1 --- [nio-8080-exec-1] [221.133.55.106] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.Connection@71af060 ((conn=1418) Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
[2024-05-20 00:27:45:244672197]  WARN  1 --- [nio-8080-exec-1] [221.133.55.106] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.Connection@6fab1304 ((conn=1419) Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
[2024-05-20 00:27:45:244672202]  WARN  1 --- [nio-8080-exec-1] [221.133.55.106] o.h.e.jdbc.spi.SqlExceptionHelper        : SQL Error: 0, SQLState: 42000
[2024-05-20 00:27:45:244672202]  ERROR 1 --- [nio-8080-exec-1] [221.133.55.106] o.h.e.jdbc.spi.SqlExceptionHelper        : HikariPool-1 - Connection is not available, request timed out after 30024ms.
00:27:45,712 |-INFO in c.q.l.co.rolling.helper.RenameUtil - Renaming file [logs/err.log] to [logs/err.2024-05-17_0.log]
00:27:45,713 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - first clean up after appender initialization
[2024-05-20 00:27:45:244672204]  WARN  1 --- [nio-8080-exec-1] [221.133.55.106] o.h.e.jdbc.spi.SqlExceptionHelper        : SQL Error: -1, SQLState: 42000
00:27:45,713 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - Multiple periods, i.e. 32 periods, seem to have elapsed. This is expected at application start.
[2024-05-20 00:27:45:244672204]  ERROR 1 --- [nio-8080-exec-1] [221.133.55.106] o.h.e.jdbc.spi.SqlExceptionHelper        : (conn=1419) Connection.setNetworkTimeout cannot be called on a closed connection
[2024-05-20 00:27:45:244672207]  ERROR 1 --- [nio-8080-exec-1] [221.133.55.106] c.d.e.common.aop.LoggingAspect           : [IP: 221.133.55.106] Error Msg: Could not open JPA EntityManager for transaction
[2024-05-20 00:27:45:244672213]  ERROR 1 --- [nio-8080-exec-1] [] o.a.c.c.C.[.[.[.[dispatcherServlet]      : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction] with root cause
java.sql.SQLSyntaxErrorException: (conn=1419) Connection.setNetworkTimeout cannot be called on a closed connection

 

에러 원인

HikariCP 커넥션 풀에서 커넥션이 닫힌 상태에서 Connection.setNetworkTimeout 메서드를 호출하려고 했기 때문에 발생한 에러

HikariCP의 maxLifetime 설정이 데이터베이스의 wait_timeout 설정보다 길기 때문에 발생할 수 있음

 

 

maxLifetime

HikariCP 커넥션 풀에서 개별 커넥션이 풀에 유지될 수 있는 최대 시간

커넥션이 이 시간보다 오래되면 사용 중이든 유휴 상태이든 상관없이 커넥션 풀에서 제거되고 새 커넥션으로 대체됨

maxLifetime을 설정하여 커넥션이 오래 지속됨에 따라 발생할 수 있는 잠재적인 문제를 예방할 수 있음

설정단위: 밀리초(ms)

기본값: 30분(1800000ms)

 

wait_timeout

MariaDB에서 유휴 상태의 연결이 종료되기까지의 최대 대기 시간

데이터베이스 서버에서 설정

클라이언트가 유휴 상태로 연결을 유지할 수 있는 최대 시간 정의

설정된 시간이 지나면 데이터베이스 서버는 유휴 연결을 자동으로 닫음

설정단위 : 초(s)

기본값: 8시간(28800초)

 

설정 권장 사항

maxLifetime을 wait_timeout값 보다 작게 설정해야함

HikariCP가 MariaDB가 커넥션을 닫기 전에 커넥션을 갱신할 수 있음

 

 

maxLifetime 설정

# application.properties
# 30분 설정

spring.datasource.hikari.maxLifetime=1800000

 

 

 

wait_timeout 확인

mariadb 를 도커 컨테이너로 실행하고 있기 때문에 컨테이너 진입해서 확인

# 도커 컨테이너 진입
docker exec -it maiadb /bin/bash

# 설정파일 편집
nano etc/mysql/my.cnf

 

설정 파일을 확인해보니 wait_timeout 설정이 명시되어 있지 않았음

설정이 명시되어있지 않다면 MariaDB의 wait_timeout 기본 설정값인 28800초(8시간)으로 설정됨

 

 

wait_timeout 을 1시간으로 설정

 

 

maxLifetime,  wait_timeout 기본값이 이미 maxLifetime의 값이 wait_timeout값 보다 작아서 이 설정은 에러를 해결할 수 없었음

 

Azure Load Balancer가 유휴 연결을 4분(기본값) 후에 닫기 때문에, 그보다 더 긴 시간 동안 유휴 상태로 있는 연결은 닫힐 수 있고 이로 인해 HikariCP가 MariaDB 연결을 사용하려 할 때 해당 연결이 이미 닫혀 있는 상황이 발생할 수 있다는 것을 알게됨

 

Azure VM 구성에서 유휴시간을 변경할 수 있음  

 

 

기본값이 4분이기 때문에 설정을 변경하기로함

최대 생존 시간을 3분으로 설정하여 3분마다 새 커넥션으로 대체하도록 하여 에러 발생을 해결함

# 3m
spring.datasource.hikari.maxLifetime=180000