Higher Availabilityへの取り組み（PostgreSQL編）

(1)

サイオステクノロジー株式会社

Higher Availability への取り組み

（PostgreSQL ARK 編）

(2)

2

© SIOS Technology, Inc.

1 Higher Availability とは

HAクラスターのHAは、高可用性（High Availability）を実現するクラスターシステムの事ですが、Higher Availabilityとは、従来のHA

クラスターで提供するHAより高い可用性を実現する事を指しています。今回はPostgreSQLを対象としたHAより高い可用性を目指す手

法について試みてみたいと考えています。

2 Higher Availability の実現方法

LifeKeeper for Linux の HA 機能を⾒た場合、以下の項目での障害検出やリカバリーの処理速度の改善がおこなえます。

 リソース障害の検出時間

 ノード障害の検出時間

 リカバリー処理に要する時間

(5)

5

3 リソース障害の検出時間

HAより高い可用性を考える為に、従来のHAクラスターでのリカバリーについて⾒てゆきたいと考えています。HAクラスターソフトウェ

アであるLifeKeeper では、以下の様なリカバリー処理が⾏われます。

 ⼀定間隔で⾏われる監視処理

 監視による障害検出

 ローカルリカバリー（障害ノードでのリカバリー）

 フェイルオーバーリカバリー（ノードを変更してサービスを起動するリカバリー）

HA より高い可用性を目指す場合、これらの処理を迅速に⾏う、もしくはリカバリーの望めない処理をスキップする等の方法を取る事で、より早いリカバリーを目指すことが可能です。具体的には以下の様な項目を短縮する事が可能と考えています。

 各リソースの状況を確認する監視処理

 フェイルオーバーリカバリー

(6)

6

この監視処理が完了するまでに要する時間は、負荷状況やハードウェアリソース、外的要因等の影響で変わってきます。次回の監視処理までに完了しなければいけないので、⼗分な間隔を設けて処理が⾏われるよう設定して頂く事が推奨されています。

(7)

7

リソース監視処理確認の為の準備

3.1

各リソースの状況を確認する監視処理は、リソース毎に下位リソースから順に実⾏されます。その為、各リソースの監視処理に要する時間を測定します。また各リソースの監視処理については通常ログ(/var/log/lifekeeper.log)に出⼒する事はありません。具体的に各リソースの監視処理にどのような処理を⾏い、その程度時間を要しているのか確認する為、各リソースのデバッグモードを有効にしてみます。

今回の検証環境は以下です。CPU コア数とメモリを多めに設定しました。

Server : VM(vSphere6) x2

CPU: Intel(R) Xeon(R) CPU E5-2660 0 @ 2.20GHz (4 core) MemTotal: 8073684 kB

Disk /dev/sda: 17.2 GB /dev/sdb: 10.7 GB Network: 1000Mbps x2

(8)

8

(9)

9

1. PostgreSQL リソースの場合は、以下のパラメータを/etc/default/LifeKeeper に追加し LifeKeeper を再起動する事で監視処理に要する時間を測定します。

LKPGSQLDEBUG=5

PostgreSQL リソースのデバッグモードを無効化する場合は、パラメータを削除して LifeKeeper を再起動する必要があります。 # lkstop;lkstart

PostgreSQL のデバッグモードを無効化する場合は、上記のパラメータを削除してください。

2. File System, Data Replication, IP リソースを監視するために、それぞれ以下のコマンドでデバッグフラグを作成し、出⼒するログから処理時間を測定します。

# flg_create –f debug_filesys # flg_create –f debug_dr # flg_create –f debug_ip

フラグ設定の状況については、以下のコマンドで確認可能です。

# flg_list

(10)

10

© SIOS Technology, Inc. # flg_remove –f debug_filesys

# flg_remove –f debug_dr # flg_remove –f debug_ip

デバッグモードは、調査を⾏う場合に詳細ログを出⼒して使用しますが、普段の運用では、ログの出⼒が冗⻑となり運用には向きません。その為、調査が終わりましたらデバッグモードは無効化してください。

各リソースの監視処理時間の測定

3.2

監視間隔を定義するパラメータ（LKCHECKINTERVAL）は、設定ファイル/etc/default/LifeKeeper に以下の様に定義されています。

LKCHECKINTERVAL=120

(11)

11

各リソースの監視処理スクリプトが要する時間を測定します。監視処理はリソース毎に下位リソースから順に監視処理が実⾏されますので、Data Replication リソース、（IP リソース、 File system リソース）、PostgreSQL リソースの順番でチェックされます。

監視処理が稼働している事を確認するため、Active ノード”pd108”で以下の様にデバッグオプションを有効化しました。監視処理に成功した場合、正常に稼働している事を⽰すログは出⼒しません。その為、デバッグログを有効にすることで、正常時に監視処理が終了した時のログを確認することが出来るようになります。

[root@pd108 ~]# flg_list debug_ip

debug_filesys debug_dr

[root@pd108 ~]#

[root@pd108 ~]# grep LKPGSQLDEBUG /etc/default/LifeKeeper LKPGSQLDEBUG=5

[root@pd108 ~]#

初期設定 120 秒での監視間隔で監視処理に要する時間を測定します。

まずはアイドル時（DB にアクセスが無い状態）の/var/log/lifekeeper.log を確認して監視処理で出⼒するログを確認して時間を測定しました。アイドル時の監視処理に要した時間は、以下にログを抜粋して張り付けました。監視処理には 15 秒を要しました。

--- アイドル時 ---

(12)

12

Aug 19 10:56:43 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000:mdadm - v3.2.6 - 25th October 2012

Aug 19 10:56:43 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000:/opt/LifeKeeper/lkadm/subsys/scsi/netraid/bin/mdadm Aug 19 10:56:43 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000:mdadm - v3.2.6 - 25th October 2012

Aug 19 10:56:43 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000:getId: -b: -p:1 -i: -s:pd108.labs.sios.com /dev/sdb1

Aug 19 10:56:43 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000:getId: /opt/LifeKeeper/lkadm/subsys/scsi/DEVNAME/bin/getId -b "/dev/sdb1" returned "/dev/sdb1"

Aug 19 10:56:43 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000:get mirrorinfo 0: pd108.labs.sios.com#0010#001type:1#0010#0010#0010#001#0010#0010#0010#001#0011

Aug 19 10:56:43 pd108 quickCheck[10972]: DEBUG:dr:::104001:get mirrorinfo 0: pd108.labs.sios.com#0010#001type:1#0010#0010#0010#001#0010#0010#0010#001#0011

Aug 19 10:56:43 pd108 quickCheck[10972]: DEBUG:dr:::104001:get mirrorinfo 0: pd109.labs.sios.com#0011#001172.16.1.109#0010#0010#0010#001#0010#0010#0010#001#0011

: <省略> :

Aug 19 10:56:58 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): DESTROY: Destroying object defined for resource (pgsql-5432)

Aug 19 10:56:58 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: starting for 5432, /usr/local/pgsql/data, /tmp, psql, pg_ctl, postgres on pd108.labs.sios.com (11071)

Aug 19 10:56:58 pd108 quickCheck[11071]: INFO:RKBase:quickCheck::000000:#011DEBUG(pgsql):#011cleaner: [our pid=11071] clients=<> Aug 19 10:56:58 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: [our pid=11071] clients=<>

Aug 19 10:56:58 pd108 quickCheck[11071]: INFO:RKBase:quickCheck::000000:#011DEBUG(pgsql):#011cleaner: [our pid=11071] utils=<> Aug 19 10:56:58 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: [our pid=11071] utils=<>

Aug 19 10:56:58 pd108 quickCheck[11071]: INFO:RKBase:quickCheck::000000:#011DEBUG(pgsql):#011cleaner: [our pid=11071] No pid(s) where found to clean up on behalf of 11071

(13)

13

11071

Aug 19 10:56:58 pd108 quickCheck[11071]: INFO:RKBase:quickCheck::000000:#011DEBUG(pgsql):#011cleaner: [our pid=11071] Set to return 0 (signaled ) Aug 19 10:56:58 pd108 lkcheck[1928]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: [our pid=11071] Set to return 0 (signaled )

--- アイドル時 ---

次に運用時（TPCC-UVa を使用した Run test を通常運用時に⾒⽴てて実施）に監視処理に要した時間を測定しました。TPCC-UVa は TPC-C に準じたベンチマークソフトウェアであり実際の物流業務におけるトランザクション処理に近い環境を作りだす想定で開発されています。また TPCC-UVa が 2014 年に久しぶりに新しいバージョン(v1.2.4 )を公開していた為、運用時の負荷を実現するベンチマークとして今回使用しました。

このベンチマークの Run test 実施時には、CPU の使用率が 50％前後まで上がりましたが、4Core で使用している事もあり、以下のログからも確認できるように、実際に監視処理に要した時間は 15 秒でした。アイドル時と比較しても差は出ませんでした。

--- Run test 時---

Aug 18 11:22:01 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000:/opt/LifeKeeper/lkadm/subsys/scsi/netraid/bin/mdadm Aug 18 11:22:01 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000:mdadm - v3.2.6 - 25th October 2012

Aug 18 11:22:01 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000:getId: -b: -p:1 -i: -s:pd108.labs.sios.com /dev/sdb1

Aug 18 11:22:01 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000:getId: /opt/LifeKeeper/lkadm/subsys/scsi/DEVNAME/bin/getId -b "/dev/sdb1" returned "/dev/sdb1"

Aug 18 11:22:01 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000:get mirrorinfo 0: pd108.labs.sios.com#0010#001type:1#0010#0010#0010#001#0010#0010#0010#001#0011

(14)

14

: <省略> :

Aug 18 11:22:16 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: starting for 5432, /usr/local/pgsql/data, /tmp, psql, pg_ctl, postgres on pd108.labs.sios.com (24585)

Aug 18 11:22:16 pd108 quickCheck[24585]: INFO:RKBase:quickCheck::000000:#011DEBUG(pgsql):#011cleaner: [our pid=24585] clients=<> Aug 18 11:22:16 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: [our pid=24585] clients=<>

Aug 18 11:22:16 pd108 quickCheck[24585]: INFO:RKBase:quickCheck::000000:#011DEBUG(pgsql):#011cleaner: [our pid=24585] utils=<> Aug 18 11:22:16 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: [our pid=24585] utils=<>

Aug 18 11:22:16 pd108 quickCheck[24585]: INFO:RKBase:quickCheck::000000:#011DEBUG(pgsql):#011cleaner: [our pid=24585] No pid(s) where found to clean up on behalf of 24585

Aug 18 11:22:16 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: [our pid=24585] No pid(s) where found to clean up on behalf of 24585

Aug 18 11:22:16 pd108 quickCheck[24585]: INFO:RKBase:quickCheck::000000:#011DEBUG(pgsql):#011cleaner: [our pid=24585] Set to return 0 (signaled ) Aug 18 11:22:16 pd108 lkcheck[11494]: ERROR:runit:uncaught_error::000000: DEBUG(pgsql): cleaner: [our pid=24585] Set to return 0 (signaled )

--- Run test 時---

上記の試験を⾏う前に、CPU:1Core メモリ 2GB の構成でアイドル時と運用時それぞれ同じ確認を⾏いました。この構成ではアイドル時 15 秒、Run test 時 24 秒と監視処理に要する時間に差がありました。しかしながら、より現実的なハードウェアリソースでの検証を⾏なおうと考え、ハードウェアのパフォーマンスを向上させました。結果として、アイドル時も運用時も監視処理にも要する時間の差は無くなりました。メモリの使用量には⼤きな変化が無かったので、マルチコア CPU のパフォーマンスが影響して、差が無くなったように考えられます。

(15)

15

アイドル時の監視処理時間が 15 秒でしたので、監視間隔の設定パラメータ（LKCHECKINTERVAL）を 13 に変更してみました。この設定を⾏った場合、ほぼ確実に以下のログが 13 秒間隔で出⼒するようになりました。

ERROR:lkcheck:::006014:LKCHECKINTERVAL parameter is too short. It is currently set to 13 seconds. It should be at least 16 seconds. Please adjust this parameter in /etc/default/LifeKeeper and execute 'kill 31681' to restart the lkcheck daemon.

上記のメッセージは、監視間隔の設定パラメータ（LKCHECKINTERVAL）が短すぎる事を⽰しています。この場合は、監視間隔毎に実⾏される監視処理は実⾏されず、終了しなかった監視処理が終了するまで継続されます。こうなると監視処理が指定の時間内に全て完了しなくなり、障害の検出に遅延が発⽣する恐れがあります。その為、監視間隔が終了するために⼗分な値に監視間隔の設定パラメータを設定変更する必要があります。

また PostgreSQL ARK には、初期値として LKCHECKINTERVAL を 26 秒以下に設定した場合、以下のメッセージを出⼒する仕様がありました。

INFO:pgsql:quickCheck::113039:The value of the LKCHECKINTERVAL 13 is lower than the required check interval of 26 for PostgreSQL. Increase the value of LKCHECKINTERVAL.

(16)

16

以上の様に監視に要する時間を測定した結果と PostgreSQL ARK の仕様を考慮し、LKCHECKINTERVAL を 26 秒に設定した状態でベンチマークを 24 時間実⾏しながら監視処理の時間を測定しました。

結論としては、24 時間内に稼働した監視処理はすべて 26 秒以内に完了していました。その為、⼗分なハードウェアリソースを要したシステムであれば、監視処理に要する時間に差が出る事は無いという結果となりました。

(17)

17

4 ノード障害の検出時間

本項目では Higher Availability を実現するため、２つめの施策であるノード監視に要する時間の短縮を⾏ってみました。

ノード監視処理は、コミュニケーションパスを経由して送信するハートビートによって⾏われます。初期設定では以下の値が使用されますので、正常時は 5 秒間隔でハートビートを送信し、死活監視を⾏います。

LCMHBEATTIME=5 # ハートビートの送信間隔 (秒)

(18)

18

コミュニケーションパスが切断された場合は 5 秒をリミットとしてハートビートを送信し、3 回失敗するとコミュニケーションパス障害となります。その為、コミュニケーションパスの障害検出まで約 15 秒かかります。

全てのコミュニケーションパスが障害として判定された場合、ノード障害と判定されノードフェイルオーバーが発⽣します。

(19)

19

ノード障害検出時間短縮の準備

4.1

パラメータを変更する前に、短縮した事が原因で発⽣するコミュニケーションパスの障害誤検知が、最終的にノード障害フェイルオーバーへとつながらないよう、事前にノード障害フェイルオーバーを停止します。こうする事で短縮時間の測定テストで不要なノード障害フェイルオーバーの発⽣を抑止します。

(20)

20

(21)

21

ノード監視短縮のためのパラメータ調整

4.2

ノード障害フェイルオーバーを停止した後、パラメータの値を調整して、コミュニケーションパスに流れるハートビートが途切れないかどうかログを監視します。最初に全ノードに対して、各パラメータの最小値を設定しました。最小値は以下となります。

LCMNUMHBEATS=2 # ハートビート切断と判定するまでの試⾏回数

パラメータの設定変更後は、LifeKeeper を再起動する必要があります。 # lkstop –f ; lkstart

最小値に変更した場合、ネットワークは正常にもかかわらず以下のメッセージを出⼒し、ハートビート喪失を検出しました。

Aug 25 14:14:31 pd109 lcm[3281]: INFO:lcm.tli_hand:::005257:missed heartbeat 1 of 2 on dev 10.1.6.109/10.1.6.108 (lcm driver number = 1256).

(22)

22

© SIOS Technology, Inc. LCMHBEATTIME=2 # ハートビートの送信間隔 (秒)

パラメータの設定変更後は、LifeKeeper を再起動する必要があります。 # lkstop –f ; lkstart

第 2 回のブログで使用した TPCC-UVa の Run test を実⾏して、通常の運用時の状態を 24 時間再現しました。その為、上記の値であっても、通常の運用には耐えられる事を確認しました。

フェイルオーバーテスト

4.3

最小値が分かりましたので、デフォルト値と最小値でノード障害テストを⾏い、フェイルオーバーが完了するまでの時間を確認しました。

 デフォルト値で要する時間

先にデフォルト値でフェイルオーバーに要する時間を測定します。誤検知によるフェイルオーバーを防ぐため⾏った、ノード障害フェイルオーバーの停止を解除してからテストを⾏います。

デフォルト値︓

(23)

23

© SIOS Technology, Inc. LCMNUMHBEATS=3 # ハートビート切断と判定するまでの試⾏回数

１．両ノードの時間が⼀致している事を確認します。

[root@pd108 ~]# ssh pd109 "hostname;date"; hostname;date root@pd109's password:

pd109.labs.sios.com

2016 年 8 月 25 日木曜日 17:24:11 JST pd108.labs.sios.com

2016 年 8 月 25 日木曜日 17:24:11 JST [root@pd108 ~]#

２． pd108 がアクティブ、pd109 がスタンバイの状態で、pd108 で以下のコマンドを実⾏してカーネルパニックを起こします。

# date ; sleep 1 ; echo c > /proc/sysrq-trigger 2016 年 8 月 25 日木曜日 17:25:43 JST

＊上記の時間の 1 秒後にカーネルパニックを引き起こしています。

(24)

24

© SIOS Technology, Inc. --- ログ抜粋 ---

Aug 25 17:26:02 pd109 eventslcm[15651]: WARN:lcd.net:::004258:Communication to pd108.labs.sios.com by 172.16.1.109/172.16.1.108 FAILED

Aug 25 17:26:02 pd109 eventslcm[15654]: WARN:lcd.net:::004261:COMMUNICATIONS failover from system "pd108.labs.sios.com" will be started.

Aug 25 17:26:02 pd109 lifekeeper[15710]: NOTIFY:event.comm_down:::010466:COMMUNICATIONS pd108.labs.sios.com FAILED

--- ログ抜粋 ---

４． Pd109 でフェイルオーバーが完了したのは以下の時間でした。

Aug 25 17:26:13 pd109 lcdmachfail[15806]: NOTIFY:lcd.lcdmf:::011065:FAILOVER RECOVERY OF MACHINE pd108.labs.sios.com FINISHED

(25)

25

 最小値で要する時間

続いて、設定可能な最小値でフェイルオーバーテストを実施します。

最小値︓

１．両ノードの時間が⼀致している事を確認します。

[root@pd108 ~]# ssh pd109 "hostname;date"; hostname;date root@pd109's password:

pd109.labs.sios.com

2016 年 8 月 25 日木曜日 18:03:42 JST pd108.labs.sios.com

2016 年 8 月 25 日木曜日 18:03:42 JST [root@pd108 ~]#

(26)

26

© SIOS Technology, Inc. [root@pd108 ~]# date ; sleep 1 ; echo c > /proc/sysrq-trigger

2016 年 8 月 25 日木曜日 18:04:21 JST

＊上記の時間の 1 秒後にカーネルパニックを引き起こしています。

３． pd109 でコミュニケーションパス障害を検出した時間は以下でした。

Aug 25 18:04:27 pd109 eventslcm[22483]: WARN:lcd.net:::004261:COMMUNICATIONS failover from system "pd108.labs.sios.com" will be started.

Aug 25 18:04:27 pd109 lifekeeper[22538]: NOTIFY:event.comm_down:::010466:COMMUNICATIONS pd108.labs.sios.com FAILED

４． Pd109 でフェイルオーバーが完了したのは以下の時間でした。

(27)

27

最小値での障害検出には、5 秒かかり、ノードフェイルオーバーが完了するまでには 16 秒の時間が必要でした。

今回の検証では、最小値を使用する事で、障害の復旧が 13 秒早くなりました。

注意事項としては、今回の検証環境は上記の設定ではハートビートの応答が 4 秒止まるだけでコミュニケーションパスの障害を検出します。その為、ノード障害やネットワーク障害が発⽣しなくても 4 秒以上応答が止まるようなシステム状況が発⽣した場合、LifeKeeper はコミュニケーションパス障害を検出します。この事で障害の誤検知となる場合もあります。

5 ローカルリカバリー無効化による切り替え処理の短縮

(28)

28

ローカルリカバリーは、成功すればフェイルオーバーが不要となりリカバリーに要する時間の短縮となりますが、失敗した場合は失敗後にフェイルオーバーをしますので、サービス停止の停止時間が⻑くなってしまいます。

今回はフェイルオーバーでしかリカバリー出来ない障害を手動で引き起こし、ローカルリカバリーにどの程度の時間を要したのか測定しました。またローカルリカバリーをオフにすることでどの程度リカバリーに要する時間が短縮されるのか確認してみました。

(29)

29

ローカルリカバリーが有効な場合のリカバリー

5.1

最初に、比較用にローカルリカバリーがオンの状態でリカバリーに要した時間を測定します。監視処理の間隔は確認した以下の最小値を使用しました。

LKCHECKINTERVAL=26

以下の様にプロセスを確認して、実⾏権限を取り外して、プロセスを停止しました。

 postgres プロセスを確認

[root@pd108 ~]# ps afx | grep postgres

11621 pts/0 S+ 0:00 \_ grep --color=auto postgres

10322 ? S 0:00 /usr/local/pgsql/bin/postgres -D /usr/local/pgsql/data -i -k /tmp -p 5432 -d 5 10324 ? Ss 0:00 \_ postgres: checkpointer process

10325 ? Ss 0:00 \_ postgres: writer process 10326 ? Ss 0:00 \_ postgres: wal writer process

10327 ? Ss 0:00 \_ postgres: autovacuum launcher process 10328 ? Ss 0:00 \_ postgres: stats collector process

 実⾏権限を停止する

[root@pd108 ~]# chmod 644 /usr/local/pgsql/bin/postgres

(30)

30

 プロセスを停止する。

[root@pd108 ~]# killall /usr/local/pgsql/bin/postgres

停止したプロセスを、次の監視処理が検出して障害として切り替わりました。そのログは以下です。

--- ログ抜粋 ---

# 障害を検出した際のログです。

Aug 31 14:13:26 pd108 quickCheck[3303]: INFO:RKBase:quickCheck::001001:Calling sendevent for resource "pgsql-5432" on server "pd108.labs.sios.com"

Aug 31 14:13:26 pd108 lkexterrlog[3435]: INFO:lkexterrlog:quickCheck:pgsql-5432:010120:Extended logs saved to /var/log/lifekeeper.err.

# ローカルリカバリーを開始しました。

Aug 31 14:13:26 pd108 recover[3430]: NOTIFY:lcd.recmain:recover:pgsql-5432:011115:BEGIN recover of "pgsql-5432" (class=pgsql event=dbfail) Aug 31 14:13:26 pd108 recover[3430]: ERROR:lcd.recover:recover:pgsql-5432:004779:resource "pgsql-5432" with id "pd108.pgsql-5432" has experienced failure event "pgsql,dbfail"

Aug 31 14:13:26 pd108 recover[3430]: INFO:lcd.recover:recover:pgsql-5432:004784:attempting recovery using resource "pgsql-5432" after failure by event "pgsql,dbfail" on resource "pgsql-5432"

Aug 31 14:13:26 pd108 dbfail[3445]: INFO:RKBase:dbfail::000000:BEGIN dbfail of "pgsql-5432" on server "pd108.labs.sios.com"

Aug 31 14:13:45 pd108 dbfail[3445]: INFO:RKBase:dbfail::001022:END failed hierarchy "dbfail" of resource "pgsql-5432" on server "pd108.labs.sios.com" with return value of 1

(31)

31

Aug 31 14:13:45 pd108 recover[3430]: ERROR:lcd.recover:recover:pgsql-5432:004786:recovery failed after event "pgsql,dbfail" using recovery at resource "pgsql-5432" on failing resource "pgsql-5432"

#ローカルリカバリーに失敗しました。

Aug 31 14:13:45 pd108 recover[3430]: ERROR:lcd.recover:recover:pgsql-5432:004028:all attempts at local recovery have failed after event "pgsql,dbfail" occurred to resource "pgsql-5432"

Aug 31 14:13:45 pd108 recover[3430]: INFO:lcd.recover:recover:pgsql-5432:004790:removing resource "pgsql-5432" for transfer # ローカルリカバリーに失敗した為、フェイルオーバー処理を開始します。

Aug 31 14:13:45 pd108 remove[4811]: INFO:RKBase:remove::000000:BEGIN remove of "pgsql-5432" on server "pd108.labs.sios.com" <省略>

# 切り替え先のノードで PostgreSQL のリソースが起動完了しました。

Aug 31 14:14:24 pd109 restore[20369]: INFO:RKBase:restore::000000:BEGIN restore of "pgsql-5432" on server "pd109.labs.sios.com" Aug 31 14:14:24 pd109 restore[20369]: INFO:pgsql:restore::113041:server starting

Aug 31 14:14:27 pd109 restore[20369]: INFO:RKBase:restore::000000:END successful restore of "pgsql-5432" on server "pd109.labs.sios.com" --- ログ抜粋 ---

(32)

32

ローカルリカバリーを無効にした場合のリカバリー処理

5.2

次に、ローカルリカバリーをオフにしてテストを⾏ってみました。

ローカルリカバリーをオフにする場合は、lkpolicy コマンドを使用してオン/オフすることが出来ます。以下のコマンドは、ノード全体のローカルリカバリーをオフにする方法となります。リソース毎に設定する場合は、”tag=”リソース名”を使用してください。

[root@pd108 ~]# lkpolicy -s LocalRecovery –off

ローカルリカバリーをオフにして同じテストを⾏った場合、以下の様にログが出⼒しました。

ログ抜粋

---# 障害を検出した際のログです。

Aug 31 15:22:46 pd108 quickCheck[14791]: INFO:RKBase:quickCheck::001001:Calling sendevent for resource "pgsql-5432" on server "pd108.labs.sios.com"

Aug 31 15:22:46 pd108 lkexterrlog[14939]: INFO:lkexterrlog:quickCheck:pgsql-5432:010120:Extended logs saved to /var/log/lifekeeper.err. #ローカルリカバリーを開始します。

Aug 31 15:22:46 pd108 recover[14934]: NOTIFY:lcd.recmain:recover:pgsql-5432:011115:BEGIN recover of "pgsql-5432" (class=pgsql event=dbfail) Aug 31 15:22:46 pd108 recover[14934]: ERROR:lcd.recover:recover:pgsql-5432:004779:resource "pgsql-5432" with id "pd108.pgsql-5432" has experienced failure event "pgsql,dbfail"

(33)

33

Aug 31 15:22:46 pd108 recover[14934]: ERROR:lcd.recover:recover:pgsql-5432:004780:local recovery is disabled by the current settings. The recovery of resource "pgsql-5432" will not be attempted.

Aug 31 15:22:46 pd108 recover[14934]: INFO:lcd.recover:recover:pgsql-5432:004790:removing resource "pgsql-5432" for transfer #フェイルオーバー処理を開始します。

Aug 31 15:22:46 pd108 remove[14949]: INFO:RKBase:remove::000000:BEGIN remove of "pgsql-5432" on server "pd108.labs.sios.com"

<省略>

# 切り替え先のノードで PostgreSQL のリソースが起動完了しました。

Aug 31 15:23:26 pd109 restore[31024]: INFO:RKBase:restore::000000:BEGIN restore of "pgsql-5432" on server "pd109.labs.sios.com" Aug 31 15:23:27 pd109 restore[31024]: INFO:pgsql:restore::113041:server starting

Aug 31 15:23:29 pd109 restore[31024]: INFO:RKBase:restore::000000:END successful restore of "pgsql-5432" on server "pd109.labs.sios.com" --- ログ抜粋 ---

ローカルリカバリーをオフにした状態では、障害を検出してから PostgreSQL リソースが起動完了するまでに 43 秒を要しました。

(34)

34

6 PostgreSQL ARK のパラメータ

その他、各リソースのパラメータについて確認しました。PostgreSQL ARK は以下の様に多数のパラメータを用意していますが、初期設定が全て最

短の処理となるよう設計されていました。その為、インストール後のパラメータのカスタマイズによる障害検出時間の短縮やリカバリー処理を早める方法がありませんでした。その為、デフォルトの設定で問題なく稼働するようであれば、パラメータ変更を⾏なわずに利用して頂くのが最も停止時間を短縮する方法でした。

以下が PostgreSQL ARK のパラメータ⼀覧です。

パラメータ名パラメータの意味設定値デフォルト値

パラメータ適応タイミング

備考

LKPGSQL_KILLPID_TIME

プロセス ID が停止した後、そのプロセスに対する再チェックを⾏うまでの時間を秒単位で指定します。

整数値 3 適宜

デフォルト値より小さい場合は、デフォルト値が設定されます。

LKPGSQL_CONN_RETRIES

旧 LKPGSQLMAXCOUNT - 操作（開始もしくは停止）を⾏った後、クライアント接続を試みる回数を指定します。

整数値 12 適宜

(35)

35

LKPGSQL_ACTION_RETRIES アクションコマンドに失敗するまで、開始と停止を

試⾏する回数を指定します。整数値 4 適宜

デフォルト値より小さい場合は、デフォルト値が設定されます。

LKPGSQL_STATUS_TIME status コマンドのタイムアウト時間を秒単位で指

定します。整数値

17 + (3 *

LKPGSQL_KILLPID_TIME) 適宜

(36)

36

備考

LKPGSQL_QCKHANG_MAX

データベースインスタンスがフェイルオーバー / sendevent を発⽣させるまでに許容される、 quickCheck がハングする回数を指定します。

整数値 2 リソース

作成時

1 より小さい場合は、デフォルト値が設定されます。

LKPGSQL_CUSTOM_DAEMON

postgres デーモン

（postgres.bin,postmaster,postgres,edb-postgres）に対する追加の別名の指定を許可します。

⽂字列（未設定）リソース

作成時

LKPGSQL_IDIRS

パラメータの値に設定した datadir のエントリを含むインスタンスを immediate オプションを使用してシャットダウンします。

⽂字列（未設定）適宜

LKPGSQL_SDIRS

パラメータの値に設定した datadir のエントリを含むインスタンスを smart オプションを使用してシャットダウンします。

(37)

37

備考

LKPGSQL_DISCONNECT_CLIENT

データベースに障害が発生している間の PostgreSQL リソース階層の振る舞いを制御します。本パラメータを有効にすると、クライアントプロセスに SIGTERM シグナルが送信され、データベースから強制的に切断され

ます。この処置は、postmaster プロセスがローカルリカ

バリー中に稼働していない場合のみに取ることができます。

0: 無効 1: 有効

1 適宜

PostgreSQL 8.2 以降では、本パラメータをご利用いただけません。

LKPGSQL_DISCONNECT_CLIENT_BYTAG

LKPGSQL_DISCONNECT_CLIENT と類似していますが、この設定は、処置をこの設定項目で指定したカンマで区切られたタグのリストに限定します。

文字列（未設定）適宜

PostgreSQL 8.2 以降では、本パラメータをご利用いただけません。

LKPGSQL_RESUME_PROC

プロセスの停止状態の検出時（プロセス状態が T ）、再開するか無視するかを決定します。

0: 無視 1: 再開

1 適宜

LKPGSQLDEBUG

PostgreSQL database kit および postgres データベースのデバッグを有効にします。 0 ～ 5 の値が有効です。

この設定項目は、オプション -d <LKPGSQLDEBUG> を使用して postmaster データベースへと渡されます。

0 ～ 5 の整数値

0 適宜

(38)

38

7 まとめ

これまでの検証で、アプリケーション監視時間間隔（LKCHKINTERVAL）の短縮（120 秒→30 秒）、ノード障害検出時間

（LCMHBEATTIME×LCMNUMHBEATS）の短縮（15 秒→4 秒）、フェイルオーバー時間の短縮（ローカルリカバリーＯＮ/OFF）などの調整（43 秒→18 秒）という PostgreSQL ARK における LifeKeeper チューニングのベストプラクティスが得られました。

アプリケーション障害の場合、30 秒以内に PostgreSQL の障害を検知し、１１秒〜18 秒でフェイルオーバーが完了します。適切なシステムリソース（CPU、メモリー）を配置することで障害検知から待機系でのサービス再開まで 60 秒以内で完了させることが可能です。

障害検知にかかる時間の短縮

ノード監視 15 秒→4 秒リソース監視 120 秒→30 秒

アプリケーション起動時間の短縮

ローカルリカバリー時のアプリの起動ローカルリカバリーON→OFF

フェイルオーバー時のアプリの起動 11 秒〜18 秒（DB のリカバリー処理が無い場合）

(39)

39

8 今後の展開

LifeKeeper のチューニングは、いかにノード障害、アプリケーション障害を素早く検知しフェイルオーバー処理を開始するかという点に関しては有効な手段であることが分かります。⼀方で、監視対象であるアプリケーションはフェイルオーバー時に待機系で起動するため、待機ノードでの DB 起動時間、DB リカバリー時間の短縮という 2 つの課題をクリアするのは非常に困難です。

Higher Availability DB のゴールである、「障害検知からフェイルオーバー完了（待機系でのサービス再開）までを 30 秒以内で完了する」という課題をクリアするためには、根本的な対応が必要です。

(40)

40

(41)

41

この仕組みを利用することで待機系での DB 起動をしなくても良い仕組みが構築できるのではないかと考え、以下のような LifeKeeper と組み合わせた構成を検討しました。

(42)

42

9 参考資料

LifeKeeper User Site

http://lk.sios.com/

LifeKeeper for Linux スタートアップガイド（v9.1.0用）

http://lk.sios.com/?p=5403

SIOS Technical Documentation

http://jpdocs.us.sios.com/

SIOS Protection Suite for Linux 9.1.0 テクニカルドキュメンテーション http://jpdocs.us.sios.com/Linux/9.1/LK4L/TechDoc/index.htm

PostgreSQL Recovery Kit管理ガイド

http://jpdocs.us.sios.com/Linux/9.1/LK4L/pgSQL/index.htm

Core パラメータ⼀覧

http://jpdocs.us.sios.com/Linux/9.1/LK4L/Parameters/index.htm#Parameters/Core_Parameters.htm

PostgreSQLパラメータ⼀覧

(43)

43

10 お問い合わせ

本書の記載内容についてのお問い合わせ先



LifeKeeper

製品の導入を検討中のお客様



LifeKeeper

製品をご購入済みのお客様

弊社パートナー営業部までお問い合わせください。

お問い合わせメールフォーム

https://www.sios.com/products/bcp/lkdk/contact/

弊社LifeKeeper製品サポート窓口までお問い合わせください。

購入後のお問い合わせ

(44)

44

11 免責事項

 本書に記載された情報は予告なしに変更、削除される場合があります。最新のものをご確認ください。

 本書に記載された情報は、全て慎重に作成され、記載されていますが、本書をもって、その妥当性や正確性についていかなる種類の保証

もするものではありません。

 本書に含まれた誤りに起因して、本書の利用者に⽣じた損害については、サイオステクノロジー株式会社は⼀切の責任を負うものではあ

りません。

 第三者による本書の記載事項の変更、削除、ホームページ及び本書等に対する不正なアクセス、その他第三者の⾏為により本書の利用者

に⽣じた⼀切の損害について、サイオステクノロジー株式会社は⼀切の責任を負うものではありません。

 システム障害などの原因によりメールフォームからのお問い合せが届かず、または延着する場合がありますので、あらかじめご了承くだ

さい。お問い合せの不着及び延着に関し、サイオステクノロジー株式会社は⼀切の責任を負うものではありません。

【著作権】

(45)

45

サイオステクノロジー株式会社

〒108-0072 東京都港区⽩⾦ 1-17-3 NBF プラチナタワー14 階電話︓ 03 - 6859 - 8686

FAX︓ 03 - 6859 - 8687

Higher Availabilityへの取り組み（PostgreSQL編）

サイオステクノロジー株式会社