Pacemaker＋DRBDでの効率的なログ分析手順

2025-09-302025-10-01

はじめに

Pacemaker と DRBD を組み合わせたクラスタシステムでは、障害が発生したときに「どのログを、どの順番で見るか」が原因特定のカギとなります。本記事では、各ログファイルの役割を簡単に解説したうえで、実務で役立つログ調査の手順を紹介します。

各ログファイルの役割

・/var/log/messages
DRBD の状態やエラーメッセージが記録され、Primary/Secondary の切替や Split-Brain の発生有無を確認できます。Pacemakerのログの一部も出力されることがあります。

・/var/log/pacemaker/pacemaker.log
リソースの開始・停止、フェイルオーバーなど Pacemaker の動きを詳細に記録します。障害時のリソース制御の流れを追うことができます。

・/var/log/corosync/corosync.log
ノード間通信やフェンシングに関する情報を出力。普段は静かですが、通信断や token timeout などが出ていれば要注意です。

・/var/lib/pacemaker/pengine/pe-input-XX.bz2　（XXは数字）
クラスタの判断根拠を保存するファイル。crm_simulate コマンドで展開すると「その時点でなぜリソース移動が起きたか」を再現可能です。

実務でのログ調査手順

DRBD の状態を確認
まず /var/log/messages を確認し、DRBD が正常かを見ます。

Primary/Secondary の切替
同期中の進捗
Split-Brain、Outdate の有無

grepの引数に’kernel: drbd’を与えるとDRBDのログだけ表示できます。

grep -i 'kernel: drbd' /var/log/messages

例えば次のログからはDRBDの同期でnode1からnode2にデータがコピーされたのち、node1のDRBDのロール（role）がSecondaryからPrimaryに変化したことが判ります。

Sep 30 08:36:33 node1 kernel: drbd r0/0 drbd0 node2: Began resync as SyncSource (will sync 0 KB [0 bits set]).
Sep 30 08:36:33 node1 kernel: drbd r0/0 drbd0 node2: Resync done (total 1 sec; paused 0 sec; 0 K/sec)
Sep 30 08:36:33 node1 kernel: drbd r0/0 drbd0 node2: pdsk( Inconsistent -> UpToDate ) repl( SyncSource -> Established ) [resync-finished]
Sep 30 08:36:33 node1 kernel: drbd r0: Preparing cluster-wide state change 3751481668: 0->all role( Primary )
Sep 30 08:36:33 node1 kernel: drbd r0: State change 3751481668: primary_nodes=1, weak_nodes=FFFFFFFFFFFFFFFC
Sep 30 08:36:33 node1 kernel: drbd r0: Committing cluster-wide state change 3751481668 (3ms)
Sep 30 08:36:33 node1 kernel: drbd r0: role( Secondary -> Primary ) [primary]

Pacemaker の制御ログを追跡
次に /var/log/pacemaker/pacemaker.log を調べ、どのリソースが停止・移動したかを確認します。

grep -i 'Stop' /var/log/pacemaker/pacemaker.log
grep -i 'Start' /var/log/pacemaker/pacemaker.log

このログはリソースの動作の異常が発生すると更新されます。

Corosync の通信ログを確認
通信断やノード障害が疑われる場合は /var/log/corosync/corosync.log を確認します。

token timeout
knet のエラー
fencing 実行の記録

このログは頻繁に更新されませんが、何らかの異常や状態の変化があると更新されます。もしノード間の通信が切れると、corosyncのログには”link: 0 is down”のような回線断の情報と、その結果タイムアウトによりノード間の通信が切れたことが記録されます。

Sep 30 09:36:07.372 [51421] node1 corosync notice  [MAIN  ] Completed service synchronization, ready to provide service.
Sep 30 09:44:11.521 [51421] node1 corosync info    [KNET  ] link: host: 2 link: 0 is down
Sep 30 09:44:11.522 [51421] node1 corosync info    [KNET  ] host: host: 2 (passive) best link: 1 (pri: 1)
Sep 30 09:44:24.338 [51421] node1 corosync info    [KNET  ] link: host: 2 link: 1 is down
Sep 30 09:44:24.338 [51421] node1 corosync info    [KNET  ] host: host: 2 (passive) best link: 1 (pri: 1)
Sep 30 09:44:24.338 [51421] node1 corosync warning [KNET  ] host: host: 2 has no active links
Sep 30 09:44:24.927 [51421] node1 corosync notice  [TOTEM ] Token has not been received in 2250 ms
Sep 30 09:44:25.677 [51421] node1 corosync notice  [TOTEM ] A processor failed, forming new configuration: token timed out (3000ms), waiting 3600ms for consensus.

pe-input ファイルで根拠を再現
最後に pe-input-XX.bz2 を crm_simulate で展開し、Pacemaker がどう判断したかを検証します。

crm_simulate -Lsと、-xオプションでpe-inputファイルを指定するとリソース毎のスコアが表示されます。

[root@node1 ~]# crm_simulate -Ls -x /var/lib/pacemaker/pengine/pe-input-261.bz2
Using the original execution date of: 2025-09-30 04:52:34Z
[ node1 node2 ]

prm_filesystem  (ocf:heartbeat:Filesystem):      Started node1
prm_mysql       (ocf:heartbeat:mysql):   Started node1
prm_vip (ocf:heartbeat:IPaddr2):         Started node1
Promoted: [ node1 ]
Unpromoted: [ node2 ]

pcmk__group_allocate: grp_apps allocation score on node1: 0
pcmk__group_allocate: grp_apps allocation score on node2: 0
pcmk__group_allocate: prm_filesystem allocation score on node1: 10
pcmk__group_allocate: prm_filesystem allocation score on node2: 0
pcmk__group_allocate: prm_mysql allocation score on node1: 10
pcmk__group_allocate: prm_mysql allocation score on node2: 0
pcmk__group_allocate: prm_vip allocation score on node1: 10
pcmk__group_allocate: prm_vip allocation score on node2: 0
・・・・

この `pe-input-XX.bz2` ファイルはPacemakerの状態が変化する毎に、ファイル名の数字をカウントアップしながら同じディレクトリにファイルを作成します。若い順からファイル内のPacemakerの情報を調べることで、何が原因でシステムに不具合が発生したか調べることができます。

実務のコツ

膨大な量のログ情報を少しでも読みやすくするため、ちょっとテクニックを紹介します。

・時系列を合わせて見る
各ログはタイムスタンプで突き合わせると、原因と結果の関係が明確になります。例えば`crm_mon -f`の出力には障害の発生した時刻が記録されます。この時刻に着目してログを調べると調査がしやすくなります。

[root@node2 ~]# crm_mon -f1
Cluster Summary:
  * Stack: corosync
  * Current DC: node1 (version 2.1.2.linbit-4.el9-ada5c3b36e2) - partition with quorum
  * Last updated: Tue Sep 30 14:58:22 2025
  * Last change:  Tue Sep 30 13:37:29 2025 by root via cibadmin on node1
  * 2 nodes configured
  * 5 resource instances configured

Node List:
  * Online: [ node1 node2 ]

Active Resources:
  * Resource Group: grp_apps (1 member inactive):
    * prm_filesystem    (ocf:heartbeat:Filesystem):      Started node1
    * prm_mysql (ocf:heartbeat:mysql):   FAILED node1
  * Clone Set: res_drbd_r0-clone [res_drbd_r0] (promotable):
    * Promoted: [ node1 ]
    * Unpromoted: [ node2 ]

Migration Summary:
  * Node: node1:
    * prm_mysql: migration-threshold=1000000 fail-count=1 last-failure='Tue Sep 30 14:58:20 2025'

Failed Resource Actions:
  * prm_mysql 30s-interval monitor on node1 returned 'not running' at Tue Sep 30 14:58:20 2025

この表示から9/30 14:58:20にリソースprm_mysqlに問題が発生したことが判ります。

・journalctl の活用
ログを期間指定で絞ると効率的です。journalctl ではログの開始時間と終了時間を使って情報を取得できます。

journalctl -u pacemaker --since "2025-09-01" --until "2025-09-02"

・grepなどのコマンドの活用
ログファイルはテキストファイルなので、Linuxのgrepやperlなどのフィルタを利用するとログの中から必要なデータを取得できます。（前出のgrep -i ‘kernel: drbd’ /var/log/messagesが例）

・ログローテーション対策
障害発生からログ調査までの期間が開くと、ログローテーションにより古いログが消えてしまうことがあります。調査前に古いログが消えないよう、/var/log をコピーしてバックアップしておきましょう。

まとめ

Pacemaker＋DRBD クラスタの障害調査では、次のような順序でログを調べると効率的です。

1: messages で DRBD の状態を確認
2: pacemaker.log でリソース制御を追跡
3: corosync.log で通信異常を確認
4: pe-input で Pacemaker の判断を再現

DRBDとPacemakerの仕組みを理解したうえで、手順に沿ってログを追えば、障害の原因をスムーズに切り分けることができます。