(O+P)ut

アウトプット



(O+P)ut

エンジニアのアウトプット
トップ > IAM > 【Keycloak/RHBK】データベース接続検証を有効にした際の挙動確認

【Keycloak/RHBK】データベース接続検証を有効にした際の挙動確認

IAM IAM-Keycloak
スポンサーリンク

はじめに

Keycloak（RedHat Build of Keycloak）ではQuarkusの設定でJDBCの接続プールの値を調整でき、その中にデータベース接続の検証を担う箇所があります。

本記事では同設定を入れた状態と入れていない状態を用意し、Keycloakの管理コンソールを操作した際の挙動がどのように変化するのかを確認しました。尚、今回は接続を取得する前の検証（フォアグラウンド検証）を有効にします。

quarkus.datasource.jdbc.background-validation-interval=0s
quarkus.datasource.jdbc.foreground-validation-interval=3s
環境情報
  • Red Hat Enterprise Linux 9.3
  • java-17-openjdk-17.0.11
  • rhbk-24.0.5
  • postgres (PostgreSQL) 16.5

全体の構成は以下でKeycloakとDBの間はネットワークを介しているのでここで通信をブロックすることで通信障害を再現します。

FWでKeycloakからDBへの通信を遮断する

検証結果

ファイアウォールにてJDBCからDBサーバに行く通信をブロックした状態で管理コンソールを操作すると、操作をする度に以下のエラーがKeycloak側に出力します。これは設定の有無変わらずの挙動で管理コンソールはもちろん利用できません。

WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] .. SQL Error: 0, SQLState: null
ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] .. Acquisition timeout while waiting for new connection
ERROR [org.keycloak.services.error.KeycloakErrorHandler] .. Uncaught server error: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection [Acquisition timeout while waiting for new connection] [n/a]

この状態でネットワークを復旧させると差分が発生します。

Quarkusにvalidationが入っていない場合、トランザクションマネージャーが以下のような警告を出して

WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX xx in state  RUN
...
WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX xx in state  CANCEL
WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012378: ReaperElement appears to be wedged: [email protected]/jdk.internal.misc.Unsafe.park(Native Method)
WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX xx in state  CANCEL_INTERRUPTED
WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012120: TransactionReaper::check worker Thread[Transaction Reaper Worker 0,5,main] not responding to interrupt when cancelling TX xx -- worker marked as zombie and TX scheduled for mark-as-rollback

変わらず管理コンソールの操作に失敗をします。

一方でvalidateの設定を入れた場合は以下のような警告が出た後に

WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX xx in state  RUN
WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id xx invoked while multiple threads active within it.
...
WARN  [org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorTrackingImpl] (Transaction Reaper Worker 0) HHH000451: Transaction afterCompletion called by a background thread; delaying afterCompletion processing until the original thread can handle it. [status=4]
WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX xx
WARN  [com.arjuna.ats.arjuna] (executor-thread-5) ARJUNA012077: Abort called on already aborted atomic action xx

ブラウザの更新等もせずに正常に管理コンソールの操作が行えるようになりました。

考察

データベースのメンテナンスやネットワークの問題が発生した際、障害状況が回復してもデータベースへの接続が失われる場合があります。
それを回避するためにアプリケーションサーバ側にてデータベース接続検証を有効にするケースがありますが、KeycloakではRed Hat build of Quarkusによっておこないます。

今回、データベース側をコマンドで停止した上で

# systemctl stop postgresql-16

復旧させると

# systemctl start postgresql-16

DBへの設定に関係なく通信をリフレッシュすると画面が操作できました。

エラーが出たケースは以下のステータスの遷移を繰り返しており、コネクションの確立に失敗しています。

TransactionReaper::check processing TX xx in state  CANCEL
TransactionReaper::check processing TX xx in state  CANCEL_INTERRUPTED
TransactionReaper::check processing TX xx in state  RUN
...

終わりに

実際に障害を発生し、Keycloakの製品ログを確認することでログと挙動の違いは確認をしました。
これがどういう仕組みで起こるのかは別途調査して記事にしたいと思います。

以上、ご参考になれば幸いです。