Spring boot Thread Pools 에러

■ 사내 개발자가 개발한 spring boot 프로젝트를 K8S에 올리는 도중 아래와 같은 에러가 발생, Mariadb를 쓰고있는 상태였습니다. 구글링을 하면서 참고한 내용을 저만의 방식으로 history 차원에서 정리해 보았습니다.

 

■ 에러 내용

2020-02-14 15:10:46.938  WARN 121294 --- [nio-8080-exec-8] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@6f87f02b (Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.

2020-02-14 15:10:51.949  WARN 121294 --- [nio-8080-exec-8] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@657f9b5b (Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
2020-02-14 15:10:56.955  WARN 121294 --- [nio-8080-exec-8] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@70abb31c (Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
2020-02-14 15:11:11.980  WARN 121294 --- [nio-8080-exec-8] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@132f2298 (Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
2020-02-14 15:11:11.981 ERROR 121294 --- [nio-8080-exec-8] i.g.j.d.resource.DataApiResource         : nested exception is org.apache.ibatis.exceptions.PersistenceException:
### Error querying database.  Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30051ms.
### The error may exist in class path resource [mapper/CodeMapper.xml]
### The error may involve io.hskim.hskim.dataapiserver.dao.CodeMapper.selectOsConnInfoByOrgCode
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30051ms.

■ 원인

• spring boot version 2.0 이상이면 Hikari가 강제적으로 기본 제공된다고 해서 개발자가 개발한 프로젝트(api server)에 Hikari 관련 소스가 없는데도 문제가 발생함 (참고:  https://github.com/spring-projects/spring-boot/wiki/Spring-Boot-2.0-Migration-Guide#configuring-a-datasource)
• 현재 mariadb 설정값은 아래와 같음 wait_timeout(활동하지 않는 커넥션을 끊을때까지 서버가 대기하는 시간)

MariaDB [(none)]> show variables like '%time%'
    -> ;
+---------------------------------------+-------------------+
| Variable_name                         | Value             |
+---------------------------------------+-------------------+
| connect_timeout                       | 10                |
| datetime_format                       | %Y-%m-%d %H:%i:%s |
| deadlock_timeout_long                 | 50000000          |
| deadlock_timeout_short                | 10000             |
| default_password_lifetime             | 0                 |
| delayed_insert_timeout                | 300               |
| explicit_defaults_for_timestamp       | OFF               |
| flush_time                            | 0                 |
| idle_readonly_transaction_timeout     | 0                 |
| idle_transaction_timeout              | 0                 |
| idle_write_transaction_timeout        | 0                 |
| innodb_flush_log_at_timeout           | 1                 |
| innodb_lock_wait_timeout              | 50                |
| innodb_old_blocks_time                | 1000              |
| innodb_rollback_on_timeout            | OFF               |
| interactive_timeout                   | 28800             |
| lc_time_names                         | en_US             |
| lock_wait_timeout                     | 86400             |
| long_query_time                       | 10.000000         |
| max_statement_time                    | 0.000000          |
| net_read_timeout                      | 30                |
| net_write_timeout                     | 60                |
| progress_report_time                  | 5                 |
| rpl_semi_sync_master_timeout          | 10000             |
| rpl_semi_sync_slave_kill_conn_timeout | 5                 |
| secure_timestamp                      | NO                |
| slave_net_timeout                     | 60                |
| slow_launch_time                      | 2                 |
| system_time_zone                      | KST               |
| tcp_keepalive_time                    | 0                 |
| thread_pool_idle_timeout              | 60                |
| thread_pool_prio_kickup_timer         | 1000              |
| time_format                           | %H:%i:%s          |
| time_zone                             | SYSTEM            |
| timed_mutexes                         | OFF               |
| timestamp                             | 1581661342.039500 |
| wait_timeout                          | 28800             |
+---------------------------------------+-------------------+
37 rows in set (0.001 sec)

 

■ Hikari 기본설정

 

• idleTimeout: pool에 일을 안하는 커넥션을 유지하는 시간입니다. 이 옵션은 minimumIdle이 maximumPoolSize보다 작게 설정되어 있을 때만 설정. pool에서 유지하는 최소 커넥션 수는 minimumIdle (A connection will never be retired as idle before this timeout.). 최솟값은 10000ms (default: 600000 (10minutes))
• maxLifetime: 커넥션 풀에서 살아있을 수 있는 커넥션의 최대 수명시간. 사용중인 커넥션은 maxLifetime에 상관없이 제거되지않습니다. 사용중이지 않을 때만 제거됩니다. 풀 전체가아닌 커넥션 별로 적용이되는데 그 이유는 풀에서 대량으로 커넥션들이 제거되는 것을 방지하기 위함입니다. 강력하게 설정해야하는 설정 값으로 데이터베이스나 인프라의 적용된 connection time limit보다 작아야합니다. 0으로 설정하면 infinite lifetime이 적용되고(idleTimeout설정 값에 따라 적용 idleTimeout값이 설정되어 있을 경우 0으로 설정해도 무한 lifetime 적용 안됨). (default: 1800000 (30minutes))

■ Hikari 설정을 아래와 같이 설정함 개발자가 만든 spring boot 소스코드에서 추가했습니다. 보통 (/src/main/resources) < 경로에 있습니다.

#hikari
spring.datasource.hikari.idle-timeout=300
spring.datasource.hikari.max-lifetime=300

■ 결론

 

• Spring boot Hikari max-lifetime이 10분 / db connection time이 5분이라고 가정

hikari는 10분이 안돼었으니 db에 계속 connection 되어있지만 db는 5분후에 지금 걸려있는 connection을 끊어버립니다. 그렇다면 5분이 지난후 hikari에서 db에 connection을 하려고 할때 에러가 발생하게 되지요. 즉, hikari max-lifetime을 db connection time 보다 작게 설정해야 합니다.