Amazon Auroraのフェイルオーバーに向けたMySQL JDBCドライバーの検証

業務でAmazon Auroraを利用しています。フェイルオーバーをサポートしてくれていたMariaDB Connector/Jを利用していたのですが、1.3.0からフェイルオーバーのサポートをしなくなったので、乗り換え先を探していました。

About MariaDB Connector/J - MariaDB Knowledge Base

調べてみたら、aws-mysql-jdbcと、aws-advanced-jdbc-wrapperが選択肢として上がりました。どちらもAWS謹製なのですが、ざっくり言うと前者がJDBCドライバーで、後者がJDBCドライバーのWrapperでMySQLPostgreSQLなどのJDBCドライバーと併せて使うものになります。

検証

先に挙げた2つのライブラリの検証をしました。結論から言うと、Read-Writeで接続先を振り分ける(読み込み時はReader、書き込み時はWriterに接続する)という要件を満たしているのが、aws-advanced-jdbc-wrapperだけだったので、これをを利用することを決めました。 aws-mysql-jdbcのこれに関する議論はこちらで行われています。

今回の環境

- Java 17
- Spring Boot 3.1.0
- aws-mysql-jdbc 1.1.7
- aws-advanced-jdbc-wrapper 2.2.2
- Amazon Aurora MySQL 8.0.mysql_aurora.3.03.1
  - Readerは1台

検証手順

1. アプリケーションの接続先URLをクラスターエンドポイントにする
2. APIを起動
3. curlで連続的にデータ書き込み用エンドポイントを叩く
4. curlで連続的にデータ参照用エンドポイントを叩く
5. 手動でフェイルオーバーを起こす

MySQL Connector/J

比較のために、MySQL Connector/Jについても検証してみました。

アプリケーションの設定

application.yml

spring:
  datasource:
    url: jdbc:mysql:replication://${クラスターエンドポイント},${Read-Onlyクラスターエンドポイント}/test_db

build.gradle

dependencies {
    runtimeOnly 'com.mysql:mysql-connector-j'
}
フェイルオーバー実行

フェイルオーバー実行すると、DB接続に失敗後に、降格した(WriterからReaderになった)インスタンスに接続しつづけるためread-onlyのトランザクションで書き込みしようとしていると怒られました。もちろんAuroraのフェイルオーバーには対応していませんでした。

2023-06-25T19:26:17.301+09:00  WARN 26196 --- [nio-8080-exec-1] com.zaxxer.hikari.pool.ProxyConnection   : HikariPool-1 - Connection com.mysql.cj.jdbc.ConnectionImpl@61e86192 marked as broken because of SQLSTATE(08S01), ErrorCode(0)

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

The last packet successfully received from the server was 34 milliseconds ago. The last packet sent successfully to the server was 37 milliseconds ago.

...

2023-06-25T19:26:17.397+09:00  WARN 26196 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@29bd6f67 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
Hibernate: insert into shop (name) values (?)
2023-06-25T19:26:27.762+09:00  WARN 26196 --- [nio-8080-exec-2] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 1836, SQLState: HY000
2023-06-25T19:26:27.763+09:00 ERROR 26196 --- [nio-8080-exec-2] o.h.engine.jdbc.spi.SqlExceptionHelper   : Running in read-only mode

Amazon Web Services (AWS) JDBC Driver for MySQL

Amazon Web Services (AWS) JDBC Driver for MySQLクラスタリングされたMySQLデータベースを利用したアプリケーションにメリットがあります。これは、MySQL Connector/J driverをベースにしており、ドロップイン互換性があります。

The AWS JDBC Driver for MySQLは、MySQL互換のAmazon Auroraのための素早いフェイルオーバーをサポートしています。クラスタリングされたデータベースの機能に加えて、Amazon RDS for MySQLやオンプレミス環境のMySQLのための機能も含んでサポートしています。

より詳しいことは、公式ドキュメントを参照してください。

アプリケーションの設定

application.yml

spring:
  datasource:
    url: jdbc:mysql:aws://${クラスターエンドポイント}/test_db
    driver-class-name: software.aws.rds.jdbc.mysql.Driver

build.gradle

dependencies {
   runtimeOnly "software.aws.rds:aws-mysql-jdbc:1.1.7"
}
フェイルオーバー実行

常にクラスターエンドポイントに接続しているので、フェイルオーバーを実行後もそのままクラスターエンドポイントに接続し続けます。ただ、フェイルオーバー中に書き込みしていたコネクションは失われます。

2023-07-09T17:16:36.030+09:00  INFO 26316 --- [nio-8080-exec-6] c.b.j.controller.ShopController          : saved shop.(id = 27420)
2023-07-09T17:16:48.181+09:00  WARN 26316 --- [nio-8080-exec-3] com.zaxxer.hikari.pool.ProxyConnection   : HikariPool-1 - Connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@28814a75 marked as broken because of SQLSTATE(08007), ErrorCode(0)
java.sql.SQLException: Transaction resolution unknown. Please re-configure session state if required and try restarting transaction.

2023-07-09T17:16:48.204+09:00 ERROR 26316 --- [nio-8080-exec-3] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: org.springframework.orm.jpa.JpaSystemException: Unable to commit against JDBC Connection] with root cause
java.sql.SQLException: Transaction resolution unknown. Please re-configure session state if required and try restarting transaction.

2023-07-09T17:16:48.645+09:00  WARN 26316 --- [nio-8080-exec-7] com.zaxxer.hikari.pool.ProxyConnection   : HikariPool-1 - Connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@61d94a02 marked as broken because of SQLSTATE(08S02), ErrorCode(0)

java.sql.SQLException: The active SQL connection has changed due to a connection failure. Please re-configure session state if required.

2023-07-09T17:16:50.323+09:00  WARN 26316 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@7708a0c5 (The active SQL connection has changed due to a connection failure. Please re-configure session state if required.). Possibly consider using a shorter maxLifetime value.
2023-07-09T17:16:50.763+09:00  WARN 26316 --- [io-8080-exec-10] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@540afcc8 (The active SQL connection has changed due to a connection failure. Please re-configure session state if required.). Possibly consider using a shorter maxLifetime value.
2023-07-09T17:16:52.421+09:00  WARN 26316 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@33480b36 (The active SQL connection has changed due to a connection failure. Please re-configure session state if required.). Possibly consider using a shorter maxLifetime value.
2023-07-09T17:16:52.845+09:00  WARN 26316 --- [io-8080-exec-10] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@7a3aa305 (The active SQL connection has changed due to a connection failure. Please re-configure session state if required.). Possibly consider using a shorter maxLifetime value.
2023-07-09T17:16:54.516+09:00  WARN 26316 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@2adac41f (The active SQL connection has changed due to a connection failure. Please re-configure session state if required.). Possibly consider using a shorter maxLifetime value.
2023-07-09T17:16:54.929+09:00  WARN 26316 --- [io-8080-exec-10] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@4f352185 (The active SQL connection has changed due to a connection failure. Please re-configure session state if required.). Possibly consider using a shorter maxLifetime value.
2023-07-09T17:16:56.601+09:00  WARN 26316 --- [nio-8080-exec-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection software.aws.rds.jdbc.mysql.shading.com.mysql.cj.jdbc.ConnectionImpl@23c98d1f (The active SQL connection has changed due to a connection failure. Please re-configure session state if required.). Possibly consider using a shorter maxLifetime value.
2023-07-09T17:16:56.641+09:00  INFO 26316 --- [nio-8080-exec-2] c.b.j.controller.ShopController          : saved shop.(id = 27421)

Amazon Web Services (AWS) JDBC Driver

Amazon Web Services (AWS) JDBC Driverは、進化したJDBC wrapperとして再設計されました。このwrapperは、Amazon Auroraのようなクラスタリングされたデータベースの機能を活用するアプリケーションをサポートするために存在するJDBCドライバーを機能拡張したものです。AWS JDBC Driverはいくつかのデータベース自身に接続する実装はしていないですが、ユーザが選択しているJDBCドライバーをAWSやAuroraの機能性をサポートを有効にできます。

詳しいことは、公式ドキュメントを参照してください。

アプリケーションの設定

application.yml

spring:
  datasource:
    url: jdbc:aws-wrapper:mysql://${クラスターエンドポイント}/test_db
    driver-class-name: software.amazon.jdbc.Driver
    hikari:
      data-source-properties:
        # プラグインを有効化。
        # readWriteSplitting:readerとwriterの接続切り替え
        # failover: Auroraのフェイルオーバーサポート
        # efm: ホストコネクション失敗のモニタリング。失敗発見率の向上
        wrapperPlugins: readWriteSplitting,failover,efm
        # フェイルオーバー時、Readerにアクセスできない場合はWriterにアクセスする(デフォルトはstrict-writer)
        failoverMode: reader-or-writer
      # フェイルオーバーに関する例外をハンドリングするため
      exception-override-class-name: software.amazon.jdbc.util.HikariCPSQLException

# 挙動確認のためのログ出力
logging:
  level:
    software.amazon.jdbc.Driver: trace
    software.amazon.jdbc.plugin.readwritesplitting: trace
    software.amazon.jdbc.plugin.staledns: trace
    software.amazon.jdbc.plugin.failover: trace

build.gradle

dependencies {
    implementation 'software.amazon.jdbc:aws-advanced-jdbc-wrapper:2.2.2'
    runtimeOnly 'com.mysql:mysql-connector-j'
}
フェイルオーバー実行

クラスターエンドポイントを指定するだけで、ライターインスタンスエンドポイントとリーダーインスタンスエンドポイントを検出してくれます。 連続的にデータ書き込み&読み込み用エンドポイントを叩き中のログを見ると、ReadOnlyのコネクションはReaderに接続していることがわかりました。念の為、CloudWatchメトリクスでDatabaseConnectionsを見てみましたが、ちゃんとReaderに接続されていました。 フェイルオーバー開始から完了までほぼダウンタイムが発生しないことがわかりました。

# アプリケーション起動中
> Task :bootRun

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v3.1.0)


 2023-07-05T00:32:43.445+09:00 TRACE 44369 --- [           main] software.amazon.jdbc.Driver              : Opening connection to jdbc:aws-wrapper:mysql://${クラスターエンドポイント}/test_db
2023-07-05T00:32:43.509+09:00 DEBUG 44369 --- [           main] s.a.j.p.f.FailoverConnectionPlugin       : failoverMode=READER_OR_WRITER
2023-07-05T00:32:43.513+09:00 TRACE 44369 --- [           main] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${クラスターエンドポイント}/': [NODE_ADDED]
2023-07-05T00:32:43.971+09:00 TRACE 44369 --- [           main] s.a.j.p.staledns.AuroraStaleDnsHelper    : Cluster endpoint resolves to x.x.x.x.
2023-07-05T00:32:43.986+09:00 TRACE 44369 --- [           main] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${クラスターエンドポイント}': [NODE_DELETED]
        Host '${リーダーインスタンスエンドポイント}': [NODE_ADDED]
        Host '${ライターインスタンスエンドポイント}': [NODE_ADDED]
2023-07-05T00:32:43.988+09:00 TRACE 44369 --- [           main] s.a.j.p.staledns.AuroraStaleDnsHelper    : Topology:
   HostSpec[host=${リーダーインスタンスエンドポイント}, port=-1, READER, AVAILABLE, weight=2450, 2023-07-04 15:32:44.108693]
   HostSpec[host=${ライターインスタンスエンドポイント}, port=-1, WRITER, AVAILABLE, weight=4, 2023-07-04 15:32:43.890895]
2023-07-05T00:32:43.989+09:00 TRACE 44369 --- [           main] s.a.j.p.staledns.AuroraStaleDnsHelper    : Writer host: HostSpec[host=${ライターインスタンスエンドポイント}, port=-1, WRITER, AVAILABLE, weight=4, 2023-07-04 15:32:43.890895]
2023-07-05T00:32:43.991+09:00 TRACE 44369 --- [           main] s.a.j.p.staledns.AuroraStaleDnsHelper    : Writer host address: x.x.x.x
2023-07-05T00:32:43.998+09:00 TRACE 44369 --- [           main] s.a.j.p.r.ReadWriteSplittingPlugin       : Writer connection set to '${クラスターエンドポイント}'
2023-07-05T00:32:44.027+09:00  INFO 44369 --- [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Added connection software.amazon.jdbc.wrapper.ConnectionWrapper@53a50b0a - com.mysql.cj.jdbc.ConnectionImpl@74ba6ff5
2023-07-05T00:32:44.029+09:00  INFO 44369 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2023-07-05T00:32:44.068+09:00  INFO 44369 --- [           main] o.f.c.i.database.base.BaseDatabaseType   : Database: jdbc:mysql://${クラスターエンドポイント}/test_db (MySQL 8.0)
2023-07-05T00:32:44.131+09:00 TRACE 44369 --- [onnection adder] software.amazon.jdbc.Driver              : Opening connection to jdbc:aws-wrapper:mysql://${クラスターエンドポイント}/test_db
2023-07-05T00:32:44.132+09:00 DEBUG 44369 --- [onnection adder] s.a.j.p.f.FailoverConnectionPlugin       : failoverMode=READER_OR_WRITER
2023-07-05T00:32:44.133+09:00 TRACE 44369 --- [onnection adder] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${リーダーインスタンスエンドポイント}': [NODE_ADDED]
        Host '${ライターインスタンスエンドポイント}': [NODE_ADDED]
2023-07-05T00:32:44.217+09:00 TRACE 44369 --- [onnection adder] s.a.j.p.staledns.AuroraStaleDnsHelper    : Cluster endpoint resolves to x.x.x.x.
2023-07-05T00:32:44.218+09:00  INFO 44369 --- [           main] o.f.core.internal.command.DbValidate     : Successfully validated 1 migration (execution time 00:00.067s)
2023-07-05T00:32:44.224+09:00 TRACE 44369 --- [onnection adder] s.a.j.p.staledns.AuroraStaleDnsHelper    : Topology:
   HostSpec[host=${リーダーインスタンスエンドポイント}, port=-1, READER, AVAILABLE, weight=2450, 2023-07-04 15:32:44.108693]
   HostSpec[host=${ライターインスタンスエンドポイント}, port=-1, WRITER, AVAILABLE, weight=4, 2023-07-04 15:32:43.890895]
2023-07-05T00:32:44.225+09:00 TRACE 44369 --- [onnection adder] s.a.j.p.staledns.AuroraStaleDnsHelper    : Writer host: HostSpec[host=${ライターインスタンスエンドポイント}, port=-1, WRITER, AVAILABLE, weight=4, 2023-07-04 15:32:43.890895]
2023-07-05T00:32:44.225+09:00 TRACE 44369 --- [onnection adder] s.a.j.p.staledns.AuroraStaleDnsHelper    : Writer host address: x.x.x.x
2023-07-05T00:32:44.231+09:00 TRACE 44369 --- [onnection adder] s.a.j.p.r.ReadWriteSplittingPlugin       : Writer connection set to '${クラスターエンドポイント}'
2023-07-05T00:32:44.248+09:00 TRACE 44369 --- [onnection adder] software.amazon.jdbc.Driver              : Opening connection to jdbc:aws-wrapper:mysql://${クラスターエンドポイント}/test_db
2023-07-05T00:32:44.249+09:00 DEBUG 44369 --- [onnection adder] s.a.j.p.f.FailoverConnectionPlugin       : failoverMode=READER_OR_WRITER
2023-07-05T00:32:44.250+09:00 TRACE 44369 --- [onnection adder] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${リーダーインスタンスエンドポイント}': [NODE_ADDED]
        Host '${ライターインスタンスエンドポイント}': [NODE_ADDED]

# 連続的にデータ書き込み&読み込み用エンドポイントを叩き中
2023-07-05T00:32:58.666+09:00  INFO 44369 --- [nio-8080-exec-4] c.b.j.controller.ShopController          : saved shop.(id = 22272)
2023-07-05T00:32:58.704+09:00  INFO 44369 --- [nio-8080-exec-6] c.b.j.controller.ShopController          : saved shop.(id = 22273)
2023-07-05T00:32:58.737+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Successfully connected to a new reader host: ${リーダーインスタンスエンドポイント}'
2023-07-05T00:32:58.738+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Reader connection set to '${リーダーインスタンスエンドポイント}'
2023-07-05T00:32:58.744+09:00  INFO 44369 --- [nio-8080-exec-9] c.b.j.controller.ShopController          : saved shop.(id = 22274)
2023-07-05T00:32:58.753+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Reader connection set to '${リーダーインスタンスエンドポイント}'
2023-07-05T00:32:58.754+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Setting the current connection to '${リーダーインスタンスエンドポイント}'
2023-07-05T00:32:58.755+09:00 DEBUG 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Switched from a writer to a reader host. New reader host: '${リーダーインスタンスエンドポイント}'
2023-07-05T00:32:58.782+09:00  INFO 44369 --- [nio-8080-exec-1] c.b.j.controller.ShopController          : saved shop.(id = 22275)
2023-07-05T00:32:58.822+09:00  INFO 44369 --- [nio-8080-exec-3] c.b.j.controller.ShopController          : saved shop.(id = 22276)
2023-07-05T00:32:58.860+09:00  INFO 44369 --- [nio-8080-exec-5] c.b.j.controller.ShopController          : saved shop.(id = 22277)
2023-07-05T00:32:58.900+09:00  INFO 44369 --- [nio-8080-exec-7] c.b.j.controller.ShopController          : saved shop.(id = 22278)
2023-07-05T00:32:58.961+09:00  INFO 44369 --- [io-8080-exec-10] c.b.j.controller.ShopController          : saved shop.(id = 22279)
2023-07-05T00:32:59.010+09:00  INFO 44369 --- [nio-8080-exec-2] c.b.j.controller.ShopController          : saved shop.(id = 22280)
2023-07-05T00:32:59.020+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Writer connection set to '${ライターインスタンスエンドポイント}'
2023-07-05T00:32:59.020+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Setting the current connection to '${ライターインスタンスエンドポイント}'
2023-07-05T00:32:59.020+09:00 DEBUG 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Switched from a reader to a writer host. New writer host: '${ライターインスタンスエンドポイント}'

# フェイルオーバー開始時
2023-07-05T00:33:33.372+09:00  INFO 44369 --- [nio-8080-exec-5] c.b.j.controller.ShopController          : saved shop.(id = 23087)
2023-07-05T00:33:33.387+09:00 DEBUG 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : Detected an exception while executing a command: Communications link failure

# フェイルオーバー中
The last packet successfully received from the server was 124 milliseconds ago. The last packet sent successfully to the server was 137 milliseconds ago.
2023-07-05T00:33:33.387+09:00 TRACE 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${フェイルオーバー前のリーダーインスタンスエンドポイント}': [WENT_DOWN, NODE_CHANGED]
2023-07-05T00:33:33.388+09:00 DEBUG 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : Starting reader failover procedure.
2023-07-05T00:33:33.390+09:00 DEBUG 44369 --- [pool-4-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : Trying to connect to reader: '${フェイルオーバー前のライターインスタンスエンドポイント}', with properties '{failoverMode=reader-or-writer, password=rootroot, database=test_db, wrapperPlugins=readWriteSplitting,failover,efm, user=root}'
2023-07-05T00:33:33.390+09:00 DEBUG 44369 --- [pool-4-thread-2] .j.p.f.ClusterAwareReaderFailoverHandler : Trying to connect to reader: '${フェイルオーバー前のリーダーインスタンスエンドポイント}', with properties '{failoverMode=reader-or-writer, password=rootroot, database=test_db, wrapperPlugins=readWriteSplitting,failover,efm, user=root}'
2023-07-05T00:33:33.416+09:00  INFO 44369 --- [nio-8080-exec-2] c.b.j.controller.ShopController          : saved shop.(id = 23088)
2023-07-05T00:33:33.455+09:00  INFO 44369 --- [nio-8080-exec-9] c.b.j.controller.ShopController          : saved shop.(id = 23089)
2023-07-05T00:33:33.463+09:00 DEBUG 44369 --- [pool-4-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : Connected to reader: '${フェイルオーバー前のライターインスタンスエンドポイント}'
2023-07-05T00:33:33.463+09:00 DEBUG 44369 --- [pool-4-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : New reader connection object: com.mysql.cj.jdbc.ConnectionImpl@1312cce0
2023-07-05T00:33:33.464+09:00 TRACE 44369 --- [nio-8080-exec-6] s.a.j.p.r.ReadWriteSplittingPlugin       : Writer connection set to '${フェイルオーバー前のライターインスタンスエンドポイント}'
2023-07-05T00:33:33.471+09:00 DEBUG 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : Connected to: HostSpec[host=${フェイルオーバー前のライターインスタンスエンドポイント} port=-1, WRITER, AVAILABLE, weight=4, 2023-07-04 15:32:43.890895]
2023-07-05T00:33:33.472+09:00 ERROR 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : The active SQL connection has changed due to a connection failure. Please re-configure session state if required.
2023-07-05T00:33:33.475+09:00  WARN 44369 --- [nio-8080-exec-6] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: 08S02
2023-07-05T00:33:33.475+09:00 ERROR 44369 --- [nio-8080-exec-6] o.h.engine.jdbc.spi.SqlExceptionHelper   : The active SQL connection has changed due to a connection failure. Please re-configure session state if required.
2023-07-05T00:33:33.482+09:00 DEBUG 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : Detected an exception while executing a command: Can't call rollback when autocommit=true
2023-07-05T00:33:33.483+09:00 TRACE 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${フェイルオーバー前のライターインスタンスエンドポイント}': [WENT_DOWN, NODE_CHANGED]
2023-07-05T00:33:33.483+09:00 DEBUG 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : Starting reader failover procedure.
2023-07-05T00:33:33.484+09:00 DEBUG 44369 --- [pool-6-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : Trying to connect to reader: '${フェイルオーバー前のライターインスタンスエンドポイント}', with properties '{failoverMode=reader-or-writer, password=rootroot, database=test_db, wrapperPlugins=readWriteSplitting,failover,efm, user=root}'
2023-07-05T00:33:33.484+09:00 DEBUG 44369 --- [pool-6-thread-2] .j.p.f.ClusterAwareReaderFailoverHandler : Trying to connect to reader: '${フェイルオーバー前のリーダーインスタンスエンドポイント}', with properties '{failoverMode=reader-or-writer, password=rootroot, database=test_db, wrapperPlugins=readWriteSplitting,failover,efm, user=root}'
2023-07-05T00:33:33.499+09:00  INFO 44369 --- [nio-8080-exec-8] c.b.j.controller.ShopController          : saved shop.(id = 23090)
2023-07-05T00:33:33.515+09:00 DEBUG 44369 --- [pool-6-thread-2] .j.p.f.ClusterAwareReaderFailoverHandler : Failed to connect to reader: '${フェイルオーバー前のリーダーインスタンスエンドポイント}'
2023-07-05T00:33:33.517+09:00 DEBUG 44369 --- [pool-4-thread-2] .j.p.f.ClusterAwareReaderFailoverHandler : Failed to connect to reader: '${フェイルオーバー前のリーダーインスタンスエンドポイント}'
2023-07-05T00:33:33.536+09:00 TRACE 44369 --- [pool-6-thread-1] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${フェイルオーバー前のライターインスタンスエンドポイント}': [WENT_UP, NODE_CHANGED]
2023-07-05T00:33:33.537+09:00 DEBUG 44369 --- [pool-6-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : Connected to reader: '${フェイルオーバー前のライターインスタンスエンドポイント}'
2023-07-05T00:33:33.537+09:00 DEBUG 44369 --- [pool-6-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : New reader connection object: com.mysql.cj.jdbc.ConnectionImpl@55e4bfde
2023-07-05T00:33:33.537+09:00 TRACE 44369 --- [nio-8080-exec-6] s.a.j.p.r.ReadWriteSplittingPlugin       : Writer connection set to '${フェイルオーバー前のライターインスタンスエンドポイント}'
2023-07-05T00:33:33.538+09:00  INFO 44369 --- [nio-8080-exec-1] c.b.j.controller.ShopController          : saved shop.(id = 23091)
2023-07-05T00:33:33.542+09:00 DEBUG 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : Connected to: HostSpec[host=${フェイルオーバー前のライターインスタンスエンドポイント}, port=-1, WRITER, AVAILABLE, weight=4, 2023-07-04 15:32:43.890895]
2023-07-05T00:33:33.542+09:00 ERROR 44369 --- [nio-8080-exec-6] s.a.j.p.f.FailoverConnectionPlugin       : The active SQL connection has changed due to a connection failure. Please re-configure session state if required.
2023-07-05T00:33:33.548+09:00 ERROR 44369 --- [nio-8080-exec-6] o.s.t.i.TransactionInterceptor           : Application exception overridden by rollback exception

2023-07-05T00:33:33.581+09:00  INFO 44369 --- [nio-8080-exec-3] c.b.j.controller.ShopController          : saved shop.(id = 23092)
2023-07-05T00:33:33.620+09:00  WARN 44369 --- [nio-8080-exec-9] s.a.j.p.r.ReadWriteSplittingPlugin       : Failed to connect to reader host: '${フェイルオーバー前のリーダーインスタンスエンドポイント}'
2023-07-05T00:33:33.623+09:00  INFO 44369 --- [nio-8080-exec-4] c.b.j.controller.ShopController          : saved shop.(id = 23093)
2023-07-05T00:33:33.628+09:00  WARN 44369 --- [nio-8080-exec-9] s.a.j.p.r.ReadWriteSplittingPlugin       : Failed to connect to reader host: '${フェイルオーバー前のリーダーインスタンスエンドポイント}'

# フェイルオーバー完了後
2023-07-05T00:33:39.373+09:00 TRACE 44369 --- [ool-11-thread-2] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${フェイルオーバー前のライターインスタンスエンドポイント}': [WENT_UP, NODE_CHANGED]
2023-07-05T00:33:39.374+09:00 DEBUG 44369 --- [ool-11-thread-2] .j.p.f.ClusterAwareReaderFailoverHandler : Connected to reader: '${フェイルオーバー前のライターインスタンスエンドポイント}'
2023-07-05T00:33:39.374+09:00 DEBUG 44369 --- [ool-11-thread-2] .j.p.f.ClusterAwareReaderFailoverHandler : New reader connection object: com.mysql.cj.jdbc.ConnectionImpl@5d8bcb8e
2023-07-05T00:33:39.374+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Reader connection set to '${フェイルオーバー前のライターインスタンスエンドポイント}'
2023-07-05T00:33:39.384+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${フェイルオーバー前のリーダーインスタンスエンドポイント}': [PROMOTED_TO_WRITER, NODE_CHANGED]
        Host '${フェイルオーバー前のライターインスタンスエンドポイント}': [NODE_DELETED]
2023-07-05T00:33:39.384+09:00 DEBUG 44369 --- [nio-8080-exec-8] s.a.j.p.f.FailoverConnectionPlugin       : Connected to: HostSpec[host=${フェイルオーバー前のリーダーインスタンスエンドポイント}, port=-1, READER, AVAILABLE, weight=2450, 2023-07-04 15:32:44.108693]
2023-07-05T00:33:39.384+09:00 ERROR 44369 --- [nio-8080-exec-8] s.a.j.p.f.FailoverConnectionPlugin       : The active SQL connection has changed due to a connection failure. Please re-configure session state if required.
2023-07-05T00:33:39.387+09:00 DEBUG 44369 --- [nio-8080-exec-8] s.a.j.p.f.FailoverConnectionPlugin       : Detected an exception while executing a command: Can't call rollback when autocommit=true
2023-07-05T00:33:39.388+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${フェイルオーバー前のライターインスタンスエンドポイント}': [WENT_DOWN, NODE_CHANGED]
2023-07-05T00:33:39.388+09:00 DEBUG 44369 --- [nio-8080-exec-8] s.a.j.p.f.FailoverConnectionPlugin       : Starting reader failover procedure.
2023-07-05T00:33:39.389+09:00 DEBUG 44369 --- [ool-14-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : Trying to connect to reader: '${フェイルオーバー前のライターインスタンスエンドポイント}', with properties '{failoverMode=reader-or-writer, password=rootroot, database=test_db, wrapperPlugins=readWriteSplitting,failover,efm, user=root}'
2023-07-05T00:33:39.391+09:00 DEBUG 44369 --- [ool-12-thread-2] .j.p.f.ClusterAwareReaderFailoverHandler : Connected to reader: '${フェイルオーバー前のライターインスタンスエンドポイント}'
2023-07-05T00:33:39.391+09:00 DEBUG 44369 --- [ool-12-thread-2] .j.p.f.ClusterAwareReaderFailoverHandler : New reader connection object: com.mysql.cj.jdbc.ConnectionImpl@6db7986c
2023-07-05T00:33:39.392+09:00 TRACE 44369 --- [io-8080-exec-10] s.a.j.p.r.ReadWriteSplittingPlugin       : Reader connection set to '${フェイルオーバー前のライターインスタンスエンドポイント}'
2023-07-05T00:33:39.398+09:00 TRACE 44369 --- [io-8080-exec-10] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${フェイルオーバー前のリーダーインスタンスエンドポイント}': [PROMOTED_TO_WRITER, NODE_CHANGED]
        Host '${フェイルオーバー前のライターインスタンスエンドポイント}': [NODE_DELETED]
2023-07-05T00:33:39.398+09:00 DEBUG 44369 --- [io-8080-exec-10] s.a.j.p.f.FailoverConnectionPlugin       : Connected to: HostSpec[host=${フェイルオーバー前のリーダーインスタンスエンドポイント}, port=-1, READER, AVAILABLE, weight=2450, 2023-07-04 15:32:44.108693]
2023-07-05T00:33:39.398+09:00 ERROR 44369 --- [io-8080-exec-10] s.a.j.p.f.FailoverConnectionPlugin       : The active SQL connection has changed due to a connection failure. Please re-configure session state if required.
2023-07-05T00:33:39.399+09:00 DEBUG 44369 --- [io-8080-exec-10] s.a.j.p.r.ReadWriteSplittingPlugin       : Detected a failover exception while executing a command: 'Connection.setReadOnly'
2023-07-05T00:33:39.399+09:00 TRACE 44369 --- [io-8080-exec-10] s.a.j.p.r.ReadWriteSplittingPlugin       : Closing all internal connections except for the current one.
2023-07-05T00:33:39.444+09:00 TRACE 44369 --- [ool-14-thread-1] s.a.j.p.f.FailoverConnectionPlugin       : Changes:
        Host '${フェイルオーバー前のリーダーインスタンスエンドポイント}': [WENT_UP, NODE_CHANGED]
2023-07-05T00:33:39.445+09:00 DEBUG 44369 --- [ool-14-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : Connected to reader: '${フェイルオーバー前のリーダーインスタンスエンドポイント}'
2023-07-05T00:33:39.445+09:00 DEBUG 44369 --- [ool-14-thread-1] .j.p.f.ClusterAwareReaderFailoverHandler : New reader connection object: com.mysql.cj.jdbc.ConnectionImpl@4cadd5e1
2023-07-05T00:33:39.446+09:00 TRACE 44369 --- [nio-8080-exec-8] s.a.j.p.r.ReadWriteSplittingPlugin       : Writer connection set to '${フェイルオーバー前のリーダーインスタンスエンドポイント}'
2023-07-05T00:33:39.451+09:00 DEBUG 44369 --- [nio-8080-exec-8] s.a.j.p.f.FailoverConnectionPlugin       : Connected to: HostSpec[host=${フェイルオーバー前のリーダーインスタンスエンドポイント}, port=-1, WRITER, AVAILABLE, weight=25, 2023-07-04 15:33:39.510702]
2023-07-05T00:33:39.451+09:00 ERROR 44369 --- [nio-8080-exec-8] s.a.j.p.f.FailoverConnectionPlugin       : The active SQL connection has changed due to a connection failure. Please re-configure session state if required.
2023-07-05T00:33:39.452+09:00  WARN 44369 --- [nio-8080-exec-8] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: 08S02
2023-07-05T00:33:39.452+09:00 ERROR 44369 --- [nio-8080-exec-8] o.h.engine.jdbc.spi.SqlExceptionHelper   : The active SQL connection has changed due to a connection failure. Please re-configure session state if required.

Liks