스프링부트 새벽 첫 요청만 unexpected end of stream이 납니다

지난번 nginx 뒤에 둔 그 스프링부트 서버입니다. 낮 시간대에는 멀쩡한데 트래픽이 거의 없는 새벽에 첫 요청이 들어오면 간헐적으로 500이 나고, 바로 다시 호출하면 정상입니다. 한 번 실패하고 나면 그 뒤로는 또 멀쩡합니다.

환경은 이렇습니다.

Spring Boot 3.2.4 (spring-boot-starter-data-jpa)
HikariCP 5.1.0 (기본값, 별도 튜닝 안 함)
MariaDB 10.6, JDBC: mariadb-java-client 3.3.x
OpenJDK 17, Ubuntu 22.04

실패할 때 애플리케이션 로그입니다.

WARN com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Failed to validate connection
  org.mariadb.jdbc.Connection@3f1a2b (Connection.setNetworkTimeout cannot be called
  on a closed connection). Possibly consider using a shorter maxLifetime value.
...
org.springframework.dao.DataAccessResourceFailureException: ...
Caused by: java.sql.SQLNonTransientConnectionException:
  (conn=1832) unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
Caused by: java.io.EOFException: unexpected end of stream, read 0 bytes from 4

DB 쪽 설정도 확인해봤습니다.

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

HikariCP는 기본값 그대로라 maxLifetime이 1800000(30분)으로 찍혀 있습니다. 지금까지 해본 건 application.yml에 connection-test-query로 SELECT 1을 넣어본 것과, 커넥션 수를 늘려본 정도인데 새벽 첫 요청 실패는 계속 재현됩니다. DB 앞단에 별도 프록시나 LB는 없고 앱에서 바로 붙습니다.

maxLifetime 기본값과 wait_timeout 600을 그대로 둬도 되는 건지, 둘 중 뭘 어느 쪽에 맞춰야 이 증상이 없어지는지 궁금합니다. 혹시 validation만으로는 못 막는 이유가 따로 있나요?

증상 그대로 전형적인 "풀에 죽은 커넥션이 남아 있다가 새벽 첫 요청이 그걸 집는" 케이스입니다. 핵심은 maxLifetime과 wait_timeout의 대소관계가 반대로 걸려 있는 거라서 validation만으로는 못 막습니다.

원인부터 짚으면, 지금 설정은 HikariCP maxLifetime=1800000(30분) > MariaDB wait_timeout=600(10분) 입니다. 새벽엔 트래픽이 없으니 풀 안 커넥션이 600초 넘게 유휴 상태로 방치되고, 그 순간 MariaDB가 서버측에서 먼저 소켓을 닫아버립니다. 그런데 HikariCP는 maxLifetime이 30분이라 아직 멀쩡하다고 보고 그 죽은 커넥션을 풀에 그대로 들고 있습니다. 첫 요청이 바로 그 끊긴 커넥션을 빌려가면서 unexpected end of stream, read 0 bytes ... (socket was closed by server) / EOFException 이 터지는 겁니다. 실패 후 HikariCP가 죽은 커넥션을 폐기하고 새로 만들기 때문에 바로 다시 호출하면 정상이 되는 것도 같은 이유입니다.

그리고 질문에 붙여주신 WARN 로그가 사실상 답을 말해주고 있습니다. Connection.setNetworkTimeout cannot be called on a closed connection 뒤에 HikariCP가 직접 Possibly consider using a shorter maxLifetime value 라고 권고하고 있죠. 공식 문서도 maxLifetime에 대해 "반드시 설정하되, DB나 인프라가 강제하는 커넥션 수명 한계보다 몇 초 짧게 두라"고 명시합니다. 지금은 정반대로 3배 길게 잡혀 있는 상태입니다.

validation(SELECT 1 / isValid)만으로 못 막는 이유는 이렇습니다.

• 검증은 커넥션을 빌려주는 그 시점 한 번만 합니다. 검증 통과 직후부터 실제 쿼리 실행 사이에 서버가 끊으면 그대로 터집니다.
• HikariCP에는 aliveBypassWindow(기본 500ms)가 있어서, 최근 사용한 커넥션은 검증을 건너뜁니다. 새벽 첫 요청 자체는 해당 안 되지만, 검증은 근본적으로 "빌려줄 때 걸러주는" 사후 방어일 뿐 애초에 커넥션이 서버에 의해 끊기는 걸 막아주지 못합니다.
• connectionTestQuery(SELECT 1)는 JDBC4 드라이버(mariadb-java-client 3.x)에선 오히려 권장되지 않습니다. 공식 문서는 JDBC4 드라이버면 이 속성을 설정하지 말고 Connection.isValid() 기반 기본 검증을 쓰라고 합니다. legacy 드라이버용 옵션입니다.

해결은 수명을 DB에 맞춰 당기고, 유휴 커넥션을 주기적으로 깨우는 것 두 가지입니다. wait_timeout=600 기준이면 maxLifetime을 그보다 넉넉히 짧게(예: 540000, 9분) 잡아 커넥션이 서버에 끊기기 전에 풀이 먼저 폐기/교체하게 하고, keepaliveTime을 함께 걸어 새벽처럼 유휴가 길 때도 주기적으로 프로브를 날려 끊김을 선제 방지합니다. keepaliveTime은 maxLifetime보다 작아야 합니다.

spring:
  datasource:
    hikari:
      max-lifetime: 540000      # 9분, wait_timeout(600s)보다 짧게
      keepalive-time: 240000    # 4분마다 유휴 커넥션 프로브 (maxLifetime보다 작게)
      connection-timeout: 30000
      # connection-test-query 는 제거 (JDBC4 isValid 사용 권장)
      # minimum-idle 은 기본값(=maximumPoolSize) 유지 권장

둘 중 뭘 어디에 맞추냐는 질문에는, DB의 wait_timeout은 그대로 두고 풀 쪽(maxLifetime)을 DB에 맞춰 내리는 방향을 권합니다. DB 타임아웃을 늘리는 건 다른 클라이언트까지 영향을 받고 끊긴 세션이 오래 남는 부작용이 있어서, 풀을 DB 한계 안쪽으로 맞추는 게 정석입니다.

적용 전후 확인은 이렇게 해보세요. 먼저 DB의 실제 적용값(글로벌과 세션이 다를 수 있음)을 보고,

SHOW GLOBAL VARIABLES LIKE 'wait_timeout';
SHOW SESSION VARIABLES LIKE 'wait_timeout';
SHOW VARIABLES LIKE 'interactive_timeout';

그리고 HikariCP 풀 동작을 디버그 로그로 올려 커넥션이 maxLifetime에 맞춰 교체되는지, keepalive 프로브가 도는지 확인하시면 됩니다.

logging.level.com.zaxxer.hikari=DEBUG
logging.level.com.zaxxer.hikari.pool.HikariPool=DEBUG

참고로 interactive_timeout이 wait_timeout과 다르게 잡혀 있고 드라이버가 interactive 플래그로 붙는 경우 실제 끊기는 기준이 달라질 수 있으니, 위 세 변수를 같이 확인해두시는 걸 권합니다. 아래 공식 문서 참고하세요.

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

🔗 https://mariadb.com/kb/en/server-system-variables/