새벽 유휴 뒤 첫 쿼리에서 Communications link failure가 납니다

Nginx 뒤에 스프링부트를 올려둔 사내용 API 서버입니다. 낮에는 요청이 꾸준한데 밤부터 새벽까지는 호출이 거의 없습니다. 문제는 아침 첫 요청, 또는 점심처럼 한참 비었다가 들어온 첫 요청에서만 간헐적으로 DB 쿼리가 터진다는 겁니다. 같은 요청을 바로 다시 날리면 멀쩡합니다.

환경은 Ubuntu 22.04, Java 17, Spring Boot 3.2.x(HikariCP), MariaDB 10.6이고 커넥터는 mysql-connector-j 8.x 입니다. 풀 옵션은 예전에 재접속 부담을 줄여보려고 max-lifetime을 0으로 둔 것 말고는 대부분 기본값입니다.

spring.datasource.hikari.max-lifetime=0
spring.datasource.hikari.connection-timeout=30000
# minimum-idle, idle-timeout 미설정, maximum-pool-size=10 기본

앱 로그에 찍히는 건 이런 식입니다.

com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure

The last packet successfully received from the server was 48,210,113 milliseconds ago. The last packet sent successfully to the server was 48,210,113 milliseconds ago.
  ...
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.

그 직전에 HikariCP 쪽 로그도 같이 보입니다.

HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@5145c183 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.

DB 자체는 멀쩡하게 떠 있고 다른 커넥션은 정상입니다. MariaDB에서 확인해보니 이렇습니다.

MariaDB [(none)]> SHOW VARIABLES LIKE 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout  | 28800 |
+---------------+-------+

마지막 패킷 수신 48210113ms 전이면 대략 13시간 전이라, wait_timeout 28800초(8시간)를 넘겨 서버가 이미 끊어버린 커넥션을 풀이 그대로 쥐고 있다가 내주는 것으로 보입니다. 지금까지는 앱을 재시작하면 당분간 괜찮아지는 식으로만 넘겼는데 근본 원인을 못 잡았습니다. HikariCP와 MariaDB 중 어느 쪽 타임아웃을 기준으로 무엇을 맞춰야 이 첫 요청 실패를 막을 수 있을까요?

진단 맞습니다. 원인은 MariaDB가 아니라 풀 설정, 정확히는 max-lifetime=0입니다. 서버 wait_timeout은 바꿀 필요 없고 풀 쪽을 맞춰야 합니다.

HikariCP 공식 문서를 보면 maxLifetime 값 0은 "최대 수명 없음(무한)"을 뜻합니다. 즉 한 번 만든 커넥션을 영원히 풀에 쥐고 있겠다는 설정입니다. 반면 MariaDB는 wait_timeout(지금 28800초=8시간) 동안 아무 통신이 없는 유휴 커넥션을 서버가 조용히 끊어버립니다. 끊을 때 클라이언트에 알려주지 않으니, 밤새 놀던 커넥션은 서버 입장에선 이미 죽었는데 풀은 살아있는 줄 알고 그대로 쥐고 있다가 아침 첫 요청에 내줍니다. 그 커넥션으로 쿼리를 날리는 순간 "Expected to read 4 bytes, read 0 bytes" (EOF) -> Communications link failure로 터지는 겁니다. 올려주신 마지막 패킷 48210113ms(약 13시간 전)이 wait_timeout 8시간을 넘긴 것도 정확히 이 그림입니다.

HikariCP가 직접 힌트도 주고 있습니다. "Failed to validate connection ... Possibly consider using a shorter maxLifetime value" 이 로그가 바로 "maxLifetime을 더 짧게 두라"는 안내입니다.

공식 문서의 권고는 명확합니다. maxLifetime은 DB나 네트워크 장비가 강제하는 커넥션 수명 제한보다 몇 초 짧게 두라는 것입니다. 그래야 서버가 끊기 전에 풀이 먼저 그 커넥션을 폐기하고 새로 맺습니다. 그러니 0으로 끄지 말고 기본값(1800000ms, 30분)을 그대로 쓰거나 wait_timeout보다 넉넉히 짧은 값으로 복구하세요. 재접속 부담 때문에 0으로 두셨다는데, 30분 수명은 유휴일 때 조용히 교체되는 수준이라 실사용에 부담이 거의 없습니다.

# 0 삭제하고 기본값(30분) 복구가 가장 안전합니다
spring.datasource.hikari.max-lifetime=1800000

# 유휴 커넥션을 선제적으로 살려두고 싶으면 keepaliveTime 추가
# (기본값 0 = 비활성. 최소 30000ms, maxLifetime보다 작아야 함)
spring.datasource.hikari.keepalive-time=300000

spring.datasource.hikari.connection-timeout=30000

maxLifetime만 정상화해도 첫 요청 실패는 대부분 사라집니다. keepaliveTime(기본 0=꺼짐)을 같이 켜면, 유휴 커넥션을 주기적으로 핑(isValid)해서 wait_timeout이나 중간 방화벽/로드밸런서가 조용히 끊는 것까지 선제적으로 막아줍니다. Nginx 뒤라고 하셨는데 DB 앞에 방화벽이나 L4가 또 끼어 있다면 그쪽 유휴 타임아웃이 8시간보다 더 짧을 수 있으니, maxLifetime은 그중 가장 짧은 제한보다도 더 짧게 잡으시는 게 안전합니다.

참고로 maxLifetime이 정상이어도 커넥션이 죽은 채 내려오는 순간을 100% 막진 못하므로, 애플리케이션 레벨 재시도나 JDBC URL에 테스트 쿼리성 옵션을 병행하기도 합니다만, 이번 케이스는 max-lifetime=0이 단일 근본 원인으로 보입니다. 먼저 이것부터 고치고 며칠 지켜보세요.

확인은 아래로 하시면 됩니다. 밤새 유휴 후 아침 첫 요청이 깨끗한지, 그리고 풀 상태 로그(leak/eviction)를 보시려면 로깅 레벨을 올려두세요.

logging.level.com.zaxxer.hikari=DEBUG
# MariaDB에서 실제 커넥션 유휴 시간이 maxLifetime 안에서 교체되는지
SHOW PROCESSLIST;  -- Time 컬럼이 wait_timeout 근처까지 치솟지 않아야 정상

근거는 HikariCP 공식 README의 maxLifetime/keepaliveTime 설명입니다. 아래 링크 참고하세요.

🔗 https://github.com/brettwooldridge/HikariCP

🔗 https://www.javadoc.io/static/com.zaxxer/HikariCP/4.0.3/com/zaxxer/hikari/HikariConfig.html