WebSphere Liberty でトランザクションのピア・リカバリーを試してみる(2/3)


WebSphere Liberty 21.0.0.9 からトランザクションのピア・リカバリーが利用できるようになったので、早速、動作を確認してみました。

[前回の記事](https://qiita.com/splendormy/items/d1d6d76de43e32a7d553)では、下記の内容を記載しました。

- ２フェーズ・コミット(2 phase commit)
- ピア・リカバリー
- 検証環境

この記事では、ピア・リカバリーの動作を確認する前段階として、WebSphere Liberty を１つだけ起動し障害を発生させることで、想定した状態で 2PC が停止していること、WebSphere Liberty の再起動でリカバリーが完了することを確認します。

# まずは、ピア・リカバリーできない状態での動作を確認
検証環境が意図した状態になっていることを確認するために、WebSphere Liberty を１つだけ起動し障害を発生させてみます。
構成としては、下図のようになります。WebSphere Liberty は kubernetes の StatefulSet で起動しています。検証環境や WebSphere Liberty の構成は、[前回の記事](https://qiita.com/splendormy/items/d1d6d76de43e32a7d553) を参照してください。

![１インスタンス.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/555650/8a028a9d-d640-b3a2-fd54-9f7e841d4f18.png)

### WebSphere Liberty を１つだけ起動
WebSphere Liberty を起動すると、３つのテーブルが DB `tranlog` 内に作成されました。
起動時に作成されるのは、server.xml 内の `transaction` タグで `recoverOnStartup="true"` を指定しているためと思われます。デフォルトの状態ではトランザクションが開始されるまでは作成されないと思われます。

|テーブル名|補足|
|:--|:--|
|WAS_LEASES_LOG|ドキュメントには説明がありません。内容は後述の通り。|
|WAS_PARTNER_LOGMYLIBERTYPVIBMWEBSPH0|Pod my-liberty-pv-ibm-websph-0 用のパートナー・ログで、トランザクションに参加した RM の情報が保存されると推測されます。|
|WAS_TRAN_LOGMYLIBERTYPVIBMWEBSPH0|Pod my-liberty-pv-ibm-websph-0 用トランザクション・ログで、個々のトランザクションの状況が保存されると推測されます。|

テーブル WAS_LEASES_LOG には、以下のような情報が１件だけ保存されており、LEASE_TIME は定期的に(約54秒毎に)更新されていました。
SERVER_IDENTITY と LEASE_OWNER は server.xml の `transaction` タグで指定した `recoveryIdentity="${env.HOSTNAME}"`の内容に、RECOVERY_GROUP は `recoveryGroup="wlp1"` の内容と想定されます。
`transactionLogDBTableSuffix="_WLP1"` と指定した情報は利用されていないようです。

```
[db2inst1@db2-db2u-0 - Db2U db2inst1]$ db2 "select * from WAS_LEASES_LOG"

SERVER_IDENTITY           RECOVERY_GROUP            LEASE_OWNER               LEASE_TIME
------------------------- ------------------------- ------------------------- --------------------
mylibertypvibmwebsph0     wlp1                       mylibertypvibmwebsph0    1632462952788

  1 record(s) selected.

```

尚、テーブル WAS_PARTNER_LOG??? と WAS_TRAN_LOG??? は WebSphere Liberty を正常に停止させると削除されていました。

### prepare 完了を記録した後にノードを停止
「トランザクション・ログに prepare 完了を記録」した後にノードを停止することで、障害をシミュレートします。(ダミー RM(1) の commit 処理中にスリープさせ、その間にノードを停止させ、障害をシミュレートします。)
Db2 と MQ は prepare が完了し、TM からの commit 指示を待つ状態となります。

ノードを停止した後に、Pod の状況を確認します。しばらくの間、Running 状態のままですが、Terminating 状態になった後は状態が変わらなくなります。(StatefulSet の Pod のため、自動的には他のノードに再スケジューリングされません。)

```
# kubectl get pod -w
NAME                         READY   STATUS    RESTARTS   AGE
my-liberty-pv-ibm-websph-0   1/1     Running   0          27m
my-liberty-pv-ibm-websph-0   1/1     Terminating   0          32m
```


Db2 でトランザクションの状況を確認すると、以下のような状況でした。

```
[db2inst1@db2-db2u-0 - Db2U db2inst1]$ db2 list indoubt transactions

 1.   originator: XA
      appl_id: 10.44.0.1.45586.210924061336                                  sequence_no: 0003 status: i
      timestamp: 09/24/2021 06:13:38 auth_id: DB2INST1
      log_full: n type: RM
      xid: 4453415724000000 360000000000017C 1670156200000001 59C0558CCD4EFB15
           1BF61DF6FD786B7E 635F5409CBEEDAA5 0000017C16701562 0000000159C0558C
           CD4EFB151BF61DF6 FD786B7E635F5409 CBEEDAA500000001 0000000000000000
           000000000002

```

MQ でトランザクションの状況を確認すると、以下のような状況でした。

```
bash-4.4$ dspmqtrn -e -m QM_TEST
AMQ7056I: Transaction number 0,24577 is in-doubt.

    XID: formatID 1463898948, gtrid_length 36, bqual_length 54
         gtrid [0000017C167015620000000159C0558CCD4EFB151BF61DF6FD786B7E635F5409CBEEDAA5]
         bqual [0000017C167015620000000159C0558CCD4EFB151BF61DF6FD786B7E635F5409CBEEDAA5000000010000000000000000000000000004]
```

Db2 と MQ の状態は想定通りの状況(in-doubt：TM からの指示を待つ状態)でした。

### 停止させたノードを起動
ノードを起動すると、Pod が再起動され、WebSphere Liberty が自身のトランザクション・ログを確認して、トランザクションのリカバリーが行われます。起動時にリカバリーが行われるのは、server.xml 内の `transaction` タグで `recoverOnStartup="true"` を指定しているためです。

WebSphere Liberty 起動時に出力された messages.log を確認すると、"Transaction service recovering 1 transaction." の出力で１つのトランザクションのリカバリーが実行されたことが確認できます。
"Recovering 5 XA resource manager(s)" となっているのは、検証用アプリケーションが、Db2 と MQ に加え、３つのダミー RM を使っているためです。

```text:一部編集
bash-4.4$ cat /logs/messages.log | grep RecoveryManager
[9/24/21 6:36:09:778 UTC] 0000003e com.ibm.tx.jta.impl.RecoveryManager   A WTRN0132I: Transaction recovery for mylibertypvibmwebsph0 initiated with server uuid cd4efb151bf61df6fd786b7e635f5409cbeedaa5 and restart epoch 1
[9/24/21 6:36:09:778 UTC] 0000003e com.ibm.tx.jta.impl.RecoveryManager   A WTRN0027I: Transaction service recovering 1 transaction.
[9/24/21 6:36:09:778 UTC] 0000003e com.ibm.tx.jta.impl.RecoveryManager   A WTRN0134I: Recovering 5 XA resource manager(s) from the transaction partner logs
[9/24/21 6:36:12:653 UTC] 0000003e com.ibm.tx.jta.impl.RecoveryManager   A WTRN0133I: Transaction recovery processing for this server is complete
bash-4.4$
```

Db2 には in-doubt なトランザクションが残っておらず、正常にリカバリーされていました。

```
[db2inst1@db2-db2u-0 - Db2U db2inst1]$ db2 list indoubt transactions
SQL1251W  No data returned for heuristic query.  SQLSTATE=00000
```

MQ にも in-doubt なトランザクションが残っておらず、正常にリカバリーされていました。

```
bash-4.4$ dspmqtrn -e -m QM_TEST
There are no matching prepared or heuristically completed transactions.
```


# 次回へ
検証用の環境が想定通りに構築されていることが確認できました。
次回は、ピア・リカバリーの検証を行います。

- [WebSphere Liberty でトランザクションのピア・リカバリーを試してみる(3/3)](https://qiita.com/splendormy/items/ddf41b9cadd8f95359c9)