DB 연결 에러(Lightsail RDS - com.zaxxer.hikari.pool.HikariPool : {} - Exception during pool initialization.)

경쓱타드·2024년 8월 24일
0

에러

목록 보기
4/7

사이즈 에러 관리를 위해서 slack에 에러 메세지를 보내면서 모니터링하고 있었다. 오늘 출근해서 일을 하고 있었는데, 유난히 에러가 많이 발생한다고 생각하고 있었다. 하지만 바빠서 확인을 못하고 있다가 퇴근하고 집에서 확인해보니 처음보는 에러가 많았다. 그래서 사이트 동작하는데 문제가 없으면 다음날 자세히 알아보려고 했는데, 사이트가 제대로 동작되지 않았다. 그래서 에러 로그들을 확인하기 시작했다.

문제 상황 확인

에러 로그 확인

2024-08-23 19:41:33.006  ERROR --- [main] com.zaxxer.hikari.pool.HikariPool : {} - Exception during pool initialization.
   at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:175)
   at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
   at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:825)
   at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:446)
   at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:239)
   at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:188)
   at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
   at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:364)
   at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206)
   at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:476)
   at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
   at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
   at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:112)
... [truncated]
2024-08-23 19:41:37.379  ERROR --- [main] com.zaxxer.hikari.pool.HikariPool : {} - Exception during pool initialization.
   at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:175)
   at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
   at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:825)
   at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:446)
   at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:239)
   at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:188)
   at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
   at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:364)
   at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206)
   at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:476)
   at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
   at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
   at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:112)
... [truncated]
2024-08-23 19:41:37.383  ERROR --- [main] org.hibernate.engine.jdbc.spi.SqlExceptionHelper : Communications link failure

The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.
2024-08-23 19:41:37.396  ERROR --- [main] org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean : Failed to initialize JPA EntityManagerFactory: [PersistenceUnit: default] Unable to build Hibernate SessionFactory; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to open JDBC Connection for DDL execution
2024-08-23 19:41:37.409  ERROR --- [main] org.springframework.boot.web.embedded.tomcat.TomcatStarter : Error starting Tomcat context. Exception: org.springframework.beans.factory.UnsatisfiedDependencyException. Message: Error creating bean with name 'jwtVerificationFilter' defined in URL [jar:file:/home/ubuntu/InsurePro_Backend/backend-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/ga/backend/oauth2/filter/JwtVerificationFilter.class]: Unsatisfied dependency expressed through constructor parameter 3; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'employeeService' defined in URL [jar:file:/home/ubuntu/InsurePro_Backend/backend-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/ga/backend/employee/service/EmployeeService.class]: Unsatisfied dependency expressed through constructor parameter 0; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'employeeRepository' defined in ga.backend.employee.repository.EmployeeRepository defined in @EnableJpaRepositories declared on JpaRepositoriesRegistrar.EnableJpaRepositoriesConfiguration: Cannot create inner bean '(inner bean)#70f43b45' of type [org.springframework.orm.jpa.SharedEntityManagerCreator] while setting bean property 'entityManager'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name '(inner bean)#70f43b45': Cannot resolve reference to bean 'entityManagerFactory' while setting constructor argument; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Invocation of init method failed; nested exception is javax.persistence.PersistenceException: [PersistenceUnit: default] Unable to build Hibernate SessionFactory; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to open JDBC Connection for DDL execution
2024-08-23 19:41:37.551  ERROR --- [main] org.springframework.boot.SpringApplication : Application run failed
   at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.onRefresh(ServletWebServerApplicationContext.java:165)
   at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:577)
   at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:147)
   at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:731)
   at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:408)
   at org.springframework.boot.SpringApplication.run(SpringApplication.java:307)
   at org.springframework.boot.SpringApplication.run(SpringApplication.java:1303)
   at org.springframework.boot.SpringApplication.run(SpringApplication.java:1292)
   at ga.backend.BackendApplication.main(BackendApplication.java:22)
   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
... [truncated]

위의 로그는 19시41분에 발생한 에러 로그이다. 같은 시간에 발생한 에러는 여러 개였다. 이 중에 핵심 에러는 SQL 연결 실패 에러일 것이다. 핵심 에러는 아래와 같다.

2024-08-23 19:41:33.006  ERROR --- [main] com.zaxxer.hikari.pool.HikariPool : {} - Exception during pool initialization.
   at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:175)
   at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
   at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:825)
   at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:446)
   at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:239)
   at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:188)
   at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
   at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:364)
   at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206)
   at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:476)
   at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
   at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
   at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:112)
... [truncated]

DB 연결 확인

문제는 어제까지만 해도 제대로 동작했고, 왜냐하면 어제 DB에 연결해서 사용하지 않은 사용자를 정리하는 작업을 했다. 그래서 어제 작업한게 문제였나 싶어서 고민을 하다가 일단 DB 연결이 안되는 것 같아서 DB 연결이 되지는 확인해보기로 했다.

연결해보니 Failed....

배포한 DB 확인(Lightsail)

어제까지 잘된 DB가 왜 연결이 안되는지 확인하기 위해서 AWS Lightsail에 들어가보았다. 인증서 만료가 되었다는 사실을 알게 되었다. 그것도 딱 어제까지였다.

해결과정

참고 사이트

공식 문서를 통해서 이를 해결하려고 한다. 공식 문서는 Lightsail의 DB에 들어갔을 때 나타난 배너의 "Learn more"를 참고해서 해결했다.

1. CloudShell 접속하기

Lightsail의 DB 인증서를 재발급하기 위해서 공식문서의 전제조건을 확인했다. Lightsail의 CloudShell에 접속해야 한다. 접속 방법은 간단하다. Lightsail에 접속하면 아래에 CloudShell 버튼이 있다. 이 버튼을 누르면 접속할 수 있다.

2. 인증서 확인

일단 내가 어떤 인증서를 가지고 있는지 확인해본다. 공식문서를 확인해서 명령어를 다음과 같이 찾을 수 있다. Database이름이랑 DatabaseRegion을 입력하면 된다. 나의 데이터베이스 이름은 Mysql이고, 사용중인 지역은 아시아 태평양(서울)이다.

  • DatabaseName : Mysql
  • DatabaseRegion : ap-northeast-2
    정리하면 위와 같고 명령어 변수 부분에 넣으면 아래와 같은 명령어가 나온다.
aws lightsail get-relational-database --relational-database-name Mysql --region ap-northeast-2 | grep "caCertificateIdentifier"

CloudShell에서 입력하면 내가 사용 중인 인증서는 "rds-ca-2019"인 것을 확인할 수 있다. 이 인증서가 만료되었으므로, 새로운 인증서를 발급해서 진행한다.

3. 인증서 재발급

공식 문서를 확인해서 아래의 명령어를 입력했다.

aws lightsail update-relational-database --relational-database-name Mysql --region ap-northeast-2 --ca-certificate-identifier rds-ca-rsa2048-g1

처음에는 위와 같이 나와서 잘되는 줄 알았다. 그런데 아래의 사진과 같이 무한히 출력만 되었다.

4. 문제 발생 1) 인증서 업데이트 실패

일단 무한 반복되니 ctrl+c 를 통해서 종료하고 다시 명령어를 입력했다. 그랬더니 정상적으로 인증서가 발급되었다! 하지만 여전히 DB에 접속되지 않았다.

aws lightsail update-relational-database --relational-database-name Mysql --region ap-northeast-2 --ca-certificate-identifier rds-ca-rsa2048-g1

5. 문제 발생 2) 인증서 적용안됨

공식문서를 참고해서 인증서를 즉시 업데이트를 할 수 있도록 명령어를 수정해서 적용해보았다.

aws lightsail update-relational-database --relational-database-name Mysql --region ap-northeast-2 --ca-certificate-identifier rds-ca-rsa2048-g1 --apply-immediately

그 후 DB Reboot를 진행한다. 그랬는데 적용 중이라고 에러창이 나왔다.

조금 기다린 후 새로 고침하니 로딩이 끝난 후 정상적으로 보였다.

6. DB 연결하기


DB 연결을 했더니 정상적이었다!

profile
백엔드 개발자를 시작으로 도메인 이해도까지 풍부한 개발자가 목표입니다!

0개의 댓글