운영중이던 서버가 정기점검 이후 mysql8 db에 붙지 못하는 장애가 발생했다. 정기점검에서 was 호스트와 db 호스트 둘다 인프라 작업으로 리눅스 커널업데이트가 있었는데, 커널업데이트란 단어에 매몰되어서 이슈 해결에 혼선이 있었다. 그 과정을 기록해본다.
시스템에 문제가 있는 것 같다는 이슈가 전달되었다. 확인해보니 아래의 에러로그와 함께 was 프로세스가 죽었다 살았다 죽었다 살았다를 반복하고 있었다.
2026-05-30 22:25:12.368 INFO 1842182 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 49999 (http)
2026-05-30 22:25:12.592 INFO 1842182 --- [main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2026-05-30 22:25:12.593 INFO 1842182 --- [main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.27]
2026-05-30 22:25:12.890 INFO 1842182 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2026-05-30 22:25:12.891 INFO 1842182 --- [main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 7057 ms
2026-05-30 22:25:13.733 INFO 1842182 --- [main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2026-05-30 22:25:14.083 INFO 1842182 --- [main] org.hibernate.Version : HHH000412: Hibernate Core {5.4.8.Final}
2026-05-30 22:25:14.577 INFO 1842182 --- [main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2026-05-30 22:25:15.198 INFO 1842182 --- [main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2026-05-30 22:25:15.640 ERROR 1842182 --- [main] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Exception during pool initialization.
java.sql.SQLNonTransientConnectionException: Public Key Retrieval is not allowed
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:111) ~[mysql-connector-j-8.2.0.jar!/:8.2.0]
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122) ~[mysql-connector-j-8.2.0.jar!/:8.2.0]
at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:815) ~[mysql-connector-j-8.2.0.jar!/:8.2.0]
at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:438) ~[mysql-connector-j-8.2.0.jar!/:8.2.0]
at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:241) ~[mysql-connector-j-8.2.0.jar!/:8.2.0]
at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:189) ~[mysql-connector-j-8.2.0.jar!/:8.2.0]
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138) ~[HikariCP-3.4.1.jar!/:na]
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:353) ~[HikariCP-3.4.1.jar!/:na]
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201) ~[HikariCP-3.4.1.jar!/:na]
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:473) [HikariCP-3.4.1.jar!/:na]uptime 을 찍어보니 인프라 작업이 있던 시간과 일치해서 리눅스 호스트가 재부팅되었다는 것을 인지했다. 이후 systemd 에 의해 was 프로세스가 올라오다가 실패하니 restart 를 반복하고 있었던 상황이다.
Public Key Retrieval is not allowed 라는 키워드로 구글링 해보니, mysql의 RSA 인증 방식 관련 글이 나왔다. 당시에는 이해하지 못하고 넘어갔다.
DB 문제인가 싶어 접속 대상 DB 에 사무실 업무 PC 의 heidisql 툴로 접속을 시도해봤다, 잘만 접속되더라. DB 문제는 아닌것으로 보았다. 이후 systemd 에서 was 서비스를 수동 shutdown 한 후, 수동으로 startup 시켜봤다. 잘 된다.
이런 상황이었던지라 원인을 알수없어 커널업데이트에 매몰되버렸던 것 같다.
칭찬하고 싶은 것은 매몰된 것이 오래가지는 않았고, Public Key Retrieval is not allowed 원리 심층 분석으로 다시 트러블슈팅해봤다. 그리고 원인을 찾았다.
우선 환경을 먼저 말해야겠다. was는 java8, mysql8.2.0 jdbc driver 이고, 접속대상 db는 8.0.41 을 쓴다. was 에서 db에 접속하던 옵션은 아래와 같다.
spring.datasource.url=jdbc:mysql://어떤ip/어떤db?useUnicode=true&characterEncoding=utf8&useSSL=false&useLegacyDatetimeCode=false&serverTimezone=Asia/SeoulPublic Key Retrieval is not allowed 란 키워드로 검색하면 단순히 allowPublicKeyRetrieval=true 옵션을 활성화해야 한다는 해결 방법만 나온다. allowPublicKeyRetrieval=true 를 활성화하면 문제는 분명 해결됬을것이다. 재밌는 것은 소스코드를 수정하지 않고, 그러니깐 allowPublicKeyRetrieval=true 없이 수동으로 startup 만 했을 뿐인데 해결됬다는 것이다. 왜 그랬던걸까?
우선 allowPublicKeyRetrieval=true 이게 무엇인지 부터 알아봤다. jdbc 옵션을 보면 (https://dev.mysql.com/doc/connector-j/en/connector-j-reference-configuration-properties.html) 해당 옵션의 기본값은 false 이다.
allowPublicKeyRetrieval 옵션은 RSA 공개키 인증 방식을 사용할지 말지에 대한 옵션이다. 도대체 공개키 방식이 왜 튀어나오는 걸까?
이는 mysql의 비밀번호 정책이 변경된 히스토리를 보면 이해할수있었다. 카카오 테크 블로그(https://tech.kakao.com/posts/712) 에서 레퍼런스를 얻었는데, mysql 5.7 에서는 우리가 흔히 알고있든 단순 해싱 알고리즘 sha 비밀번호 방식을 사용해 인증처리를 한다. mysql8 부터는 알고리즘이 바뀌었다, 비밀번호를 캐싱해서 처리하는 caching_sha2_password 을 사용하는 것을 기본으로 사용한다. 알고리즘은 각각의 로그인 계정마다 어떤 알고리즘을 사용할지 선택할수있다.
아래의 쿼리를 날리면, 해당 계정이 어떤 알고리즘을 쓰는 지 알수있다.
SELECT user, host, plugin FROM mysql.user WHERE user = '계정';
그렇다면 비밀번호 캐싱이란 뭘까? mysql 테크 블로그에 자세히 나와있다(https://dev.mysql.com/blog-archive/a-tale-of-two-password-authentication-plugins/)
mysql 의 비밀번호 인증은 COMPLETE 모드와 FAST 모드 라는 2가지 모드로 동작한다.
COMPLETE 모드는 우리가 흔히 아는 비밀번호 대조 방식 인증을 말하고, FAST 모드는 비밀번호 대조를 하지 않고 mysql 서버에서 캐싱한 어떠한 데이터를 참고해 인터뷰 방식으로 처리하는 방식이다. 인터뷰 방식? 뒤에서 자세히 설명하겠다.
2개의 모드가 있는 이유는 아래와 같은데, mysql 인증 플러그인은 무차별 대입 공격에 된통당한적이 있던모양인지, 비밀번호 저장 할 때 sha 해싱 알고리즘을 5000번이나 돌려버리는 기행을 하고 있다. 이 말이 의미하는 것은 COMPLETE 모드를 할때마다 비밀번호 대조에 엄청난 오버헤드가 발생한단 말이다. 쉽게 말해 겁나 느리다.
FAST 모드는 앞서 말한 비밀번호 캐싱과 관련이 있는 모드인데, 이 모드는 간단히 말해 한번 COMPLETE 모드로 로그인하고 난 계정의 비밀번호 관련 정보를 캐싱해두었다가, 다시 해당 계정이 로그인할때 COMPLETE 모드를 거치지 않고 간단한 질의응답( challenge-response 라 한다) 을 주고 받아서 신원을 확인하는 방법이다.
challenge-response 을 어떻게 처리하는지 구체적인 내용은 알 수 없었는데, 상상해보면 당신의 고향은 어디입니까? 비밀번호 끝 4글자를 말해보시오. 와 같은 인터뷰 방식의 질의응답과 유사한 방법이라 할수있다.
공부한 것을 참고해 다시 이슈를 생각해보자. 앞서 인프라 작업으로 인해 mysql8 db 역시 재부팅되었는데, 재부팅되면서 캐싱된 데이터가 날라가버리면서 COMPLETE 모드를 요구하게 되어 장애가 발생했던 것이다.
그렇다면 왜 해결이 되었을까? 이유는 참으로 황당하기 그지없다. 그저 같은 계정으로 누군가가 동일한 시간에 로그인해버리면서 해결된 것이고.. 그 누군가는 장애 해결을 위해 트러블슈팅을 하던 나였다. DB 하드웨어 문제가 있나 싶어 사무실 업무PC로 해당 db에 heidsiql 툴로 접속을 해보고 '어 잘되는데?' 라며 삽질을 하던 중에 해결된 것.
동일한 상황이 연출되면 분명 다시 이슈가 재현될 것이다. allowPublicKeyRetrieval=true 옵션을 활성화해서 방지하기로 했다.
이제부터는 조금 옆으로 새는 이야기로, 트러블슈팅 과정에서 겪었던 TMI
- dev 환경은 mysql5.7 을 쓰다가 최근 mysql 8로 업그레이드 했다. mysql 5.7 에서는 FAST 모드 개념이 없기에 여지껏 이런 이슈를 겪지 못했었다.
- product 환경은 상대적으로 dev 환경에 비해 메인터넌스란 이유로 재부팅이 잦은 편이지만 비슷한 이슈를 겪은 적이 없다. 그 이유는 dev 환경은 ssl 를 사용하지 않고, product 존은 ssl 을 사용하는 환경에서 오는 차이였다.
COMPLETE 모드는 ssl 을 사용한다면 ssl 채널을 통해 비밀번호를 전달하는 식으로 처리한다. 그러나 ssl 을 사용하지 않는 db라면 RSA 공개키 방식으로 비밀번호를 캡슐화해서 전달하기 때문에 allowPublicKeyRetrieval=true 옵션이 필요해진다.