“Higher Availability” DBを目指して、LifeKeeperをチューニングしてみました。(第3回)~その他の短縮方法を考える

    failover process flow chart

    こんにちは。
    サイオステクノロジーの宇野です。LifeKeeperの開発を担当しています。

    第1回でリソース監視とリカバリーの短縮第2回でノード監視とリカバリーの短縮に取り組んできました。今回はこれまで紹介した以外の方法について考えてみたいと思います。

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

    LifeKeeperではリソース障害発生時、フェイルオーバーによるリカバリーの前に、障害の発生したノードでの復旧(ローカルリカバリー)を試みます。この処理に成功した場合、フェイルオーバーは引き起こさずに、稼働していたアクティブノードで復旧します。失敗した場合は、フェイルオーバーに処理が移ります。

    failover process flow chart
    フェイルオーバーの仕組み

    ローカルリカバリーは、成功すればフェイルオーバーが不要となりリカバリーに要する時間の短縮となりますが、失敗した場合は失敗後にフェイルオーバーをしますので、逆にサービスの停止時間が長くなってしまいます。
    今回は、フェイルオーバーでしかリカバリーできない障害を手動で引き起こし、ローカルリカバリーにどの程度の時間を要したのか測定しました。またローカルリカバリーをオフにすることで、どの程度リカバリーに要する時間が短縮されるのか確認してみました。

    リソース障害時の処理となりますので、以下のパラメータの間隔で行われる監視処理で異常と判定される障害を引き起こします。具体的にはpostgresの実行ファイルが再起動出来なくする(実行ファイルから実行権限を取り除く)擬似障害環境を用意して、postgresプロセスを停止しました。

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

    LKCHECKINTERVAL=26

    ローカルリカバリーがONの場合

    以下のようにプロセスを確認し、実行権限を取り外してからプロセスを停止しました。

    • 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
      *必ず、元の権限を確認しておきます。またテストが終わったら、元の権限に戻します。
    •  プロセスを停止する
      [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
    Aug 31 14:13:45 pd108 lkexterrlog[4780]: INFO:lkexterrlog:recover:pgsql-5432:010120:Extended logs saved to /var/log/lifekeeper.err.
    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”

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

    次に、ローカルリカバリーをオフにして同じテストを行ってみます。

    ローカルリカバリーがOFFの場合

    ローカルリカバリーをオフにする場合は、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”

    #ローカルリカバリーは無効化されている事を確認。そのため、ローカルリカバリーは行われません。
    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秒を要しました。
    今回の環境ではローカルリカバリーのオン、オフで61秒、43秒と18秒程度の差が確認できました。ローカルリカバリーはフェイルオーバーを起こさずに障害を復旧する可能性のある処理ですが、復旧しない場合もあります。そのため、上記のように事前にローカルリカバリーをオフにして運用する事も可能です。

    2. PostgreSQL ARKのパラメータ

    その他、各リソースのパラメータについて確認しました。
    PostgreSQL ARKは以下のように多数のパラメータを用意していますが、初期設定が全て最短の処理となるよう設計されていました。そのため、インストール後に、パラメータのカスタマイズによる障害検出時間の短縮やリカバリー処理を早めることはできそうにありませんでした。つまり、デフォルトの設定で問題なく稼働するようであれば、パラメータ変更を行なわずに利用するのが最も停止時間を短縮する方法となっています。

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

    postgresql-ark-parameter
    postgresql ark パラメータ一覧(クリックすると拡大されます)

    3. まとめ

    これまでの検証で、アプリケーション監視時間間隔(LKCHKINTERVAL)の短縮(120秒→30秒)、ノード障害検出時間(LCMHBEATTIME×LCMNUMHBEATS)の短縮(15秒→4秒)、フェイルオーバー時間の短縮(ローカルリカバリーON/OFF)などの調整(43秒→18秒)というPostgreSQL ARKにおけるLifeKeeperチューニングのベストプラクティスが得られました。
     アプリケーション障害の場合、30秒以内にPostgreSQLの障害を検知し、11秒~18秒でフェイルオーバーが完了します。適切なシステムリソース(CPU、メモリー)を配置することで障害検知から待機系でのサービス再開まで60秒以内で完了させることが可能です。

    障害検知にかかる時間の短縮
    ノード監視       15秒→4秒
    リソース監視      120秒→30秒

    アプリケーション起動時間の短縮
    ローカルリカバリー時のアプリの起動     ローカルリカバリーON→OFF
    フェイルオーバー時のアプリの起動     11秒~18秒(DBのリカバリー処理が無い場合)
    DBのリカバリー処置に要する時間      障害時の書き込み系トランザクションに依存するため不定

    以上、3回にわたってHigher Availability(より高い可用性)を実現する手法をご紹介してきました。これ以外の方法についても施策を考えていますので、また検証を行い次第、紹介していきたいと思います。

    4. 今後の展開

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

    Higher Availability DBのゴールである、「障害検知からフェイルオーバー完了(待機系でのサービス再開)までを30秒以内で完了する」という課題をクリアするためには、根本的な対応が必要です。
    そこで私たちが着目したのが、EnterpriseDB xDB マルチマスターレプリケーションです。DBサーバーが相互に表の同期(レプリケーション)を行い、どのDBサーバーにアクセスしても参照・更新が可能となるものです。

    xDB Multi Master Replication(MMR)基本構成
    xDB Multi Master Replication(MMR) 基本構成
    • 全てのDBノードがマスターノードとして動作し相互にレプリケーションを実行
    • どのノードのDBに対しても参照・更新が可能

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

    xDB MMR+LifeKeeper-structure
    xDB MMRとLifeKeeperの組み合わせ構成

    xDB MMR + LifeKeeper構成に関しては、現在検証作業を実施中です。検証結果については順次、当ブログにてお伝えして行く予定です。