"藤元秀樹@IDS"
h.fuj****@ids*****
2009年 4月 22日 (水) 15:08:14 JST
池田様 お世話になります。藤元です。 早速のご回答ありがとうございます。 > ハートビートラインがアップダウンを繰り返しているため > 不完全なメッセージを受信してしまったようです。 > 本来であれば、name=value という形式のメッセージを > 期待している箇所で '=' を含むメッセージを > 受け取れなかったため、上記の様なエラーを出力していると思われます。 > 内部エラーではなく、受信メッセージが不完全ということですね ハートビートラインがシリアルだと不安定になりやすい? イーサネットだったら?という疑問はありますが、、 > 抜粋されたログメッセージには時刻情報がありませんが > 「繰り返しログ」が60分ほど続いたあとに > 「緊急停止ログ」が出力されているのでしょうか? > ログ時刻を確認しましたら、まさにそのとおりでした。 60分後に緊急停止ログが出力されていました。 30回というのは、偶然ということですね > V1モードは使用したことがなかったため > 今回の例ははじめて見ましたが、V1モード、V2モードで > 緊急停止動作が異なる部分も多いのではないかと予想されます。 > このため、緊急停止の条件を網羅的に列挙することは困難です。 > また、Heartbeatの各バージョン(2.0.8, 2.1.3, 2.1.4 )でも > 緊急停止動作は異なります。 > 2.1.3以降では、Heartbeatの子プロセス(crmd, cibなど)が > 停止した際もサーバ再起動が発生します。 V1モードとV2モードやHeartbeatのバージョンによっても動作が違うのですね 大変勉強になりました。 > 今回の障害では以下の動作が推測できます。 > (1) サーバ過負荷状態でハートビートラインのアップダウン発生 > (2) ハートビートラインのアップダウンにより、メッセージの受信漏れ発生 > (3) V1モードのため、60分後に強制停止を発生させるタイムアウト開始 > (4) 60分後もタイムアウトの設定が有効であれば、強制終了 > ※ 60分以内にハートビートラインが完全復旧し、タイムアウトが破棄されれば > 強制終了は発生しないのかもしれません。 > 今回の障害に関する裏づけが取れました。 的確なご回答ありがとうございました。 > 池田です。 > > >> ○内部エラー?ログ >> ha-debug ================================================== >> host1 heartbeat: [10560]: WARN: ha_msg_add_nv_depth: line doesn't >> contain '=' >> host1 heartbeat: [10560]: info: >>> >> host1 heartbeat: [10560]: ERROR: NV failure (msgfromsteam): [>>> ] >> > > ハートビートラインがアップダウンを繰り返しているため > 不完全なメッセージを受信してしまったようです。 > 本来であれば、name=value という形式のメッセージを > 期待している箇所で '=' を含むメッセージを > 受け取れなかったため、上記の様なエラーを出力していると思われます。 > > >> ○繰り返しログ >> ha-debug ================================================== >> host1 heartbeat: [10558]: CRIT: Cluster node host2 returning after >> partition. >> host1 heartbeat: [10558]: info: For information on cluster partitions, >> See URL: http://linux-ha.org/SplitBrain >> host1 heartbeat: [10558]: WARN: Deadtime value may be too small. >> host1 heartbeat: [10558]: info: See FAQ for information on tuning >> > deadtime. > >> host1 heartbeat: [10558]: info: URL: http://linux-ha.org/FAQ#heavy_load >> > > >> host1 heartbeat: [10558]: WARN: Shutdown delayed until current resource >> activity finishes. >> > > 上記のログメッセージから > should_drop_message()やhb_giveup_resources()が > 呼び出されていることがわかります。 > > should_drop_message()には > DoManageResources=TRUEの場合(V1モードの場合、TRUEのようです) > cause_shutdown_restart()を呼び出す処理が記述されています。 > cause_shutdown_restart()では60分後に > hb_emergency_shutdown()を呼び出すタイムアウトを仕掛けます。 > > >> ○緊急停止ログ >> ha-debug ================================================== >> host1 heartbeat: [10558]: CRIT: Emergency Shutdown: Attempting to kill >> everything ourselves >> ========================================================== >> > > 上記のメッセージはhb_emergency_shutdown()から出力されています。 > > 抜粋されたログメッセージには時刻情報がありませんが > 「繰り返しログ」が60分ほど続いたあとに > 「緊急停止ログ」が出力されているのでしょうか? > > >> 1.Heartbert内部エラー?が発生し、その後30回繰り返した後、緊急停止し >> ていたように見えます。 >> > > 今回の障害では以下の動作が推測できます。 > (1) サーバ過負荷状態でハートビートラインのアップダウン発生 > (2) ハートビートラインのアップダウンにより、メッセージの受信漏れ発生 > (3) V1モードのため、60分後に強制停止を発生させるタイムアウト開始 > (4) 60分後もタイムアウトの設定が有効であれば、強制終了 > ※ 60分以内にハートビートラインが完全復旧し、タイムアウトが破棄されれば > 強制終了は発生しないのかもしれません。 > > >> この内部エラー?はどのような不具合なのでしょうか >> > > 上記の動作とログメッセージを付き合わせると > (2) ハートビートラインのアップダウンにより、メッセージの受信漏れ発生 > に該当する部分かと思います。 > > >> 2.Heartbertが緊急停止する条件とはどんな時なのでしょうか >> > > V1モードは使用したことがなかったため > 今回の例ははじめて見ましたが、V1モード、V2モードで > 緊急停止動作が異なる部分も多いのではないかと予想されます。 > このため、緊急停止の条件を網羅的に列挙することは困難です。 > また、Heartbeatの各バージョン(2.0.8, 2.1.3, 2.1.4 )でも > 緊急停止動作は異なります。 > 2.1.3以降では、Heartbeatの子プロセス(crmd, cibなど)が > 停止した際もサーバ再起動が発生します。 > > 参考 > http://www.atmarkit.co.jp/flinux/rensai/heartbeat03/heartbeat03b.html > > > 以上よろしくお願いいたします。 > > 池田淳子 > > > >> -----Original Message----- >> From: linux****@lists***** >> [mailto:linux****@lists*****] On Behalf Of "藤元秀 >> > 樹 > >> @IDS" >> Sent: Tuesday, April 21, 2009 7:21 PM >> To: linux****@lists***** >> Subject: [Linux-ha-jp] Heartbeat内部エラー?と緊急停止条件 >> >> はじめまして、藤元と申します。 >> >> 初めての投稿ですが、宜しくお願い致します。 >> >> Heartbeat障害が発生し、分析調査を行っております。 >> >> 構成 >> Webサーバ×2台(host1:active/host2:passive) >> OS:RHEL ES4.0 update5 >> karnel:2.6.9-55.EL >> apache1.3.34 >> >> Heartbeat:2.0.8 >> モード:V1互換モード >> ハートビートライン:シリアル1系統のみ >> >> authkeys ---------------- >> auth 1 >> 1 crc >> ------------------------ >> >> ha.cf -------------------- >> debugfile /var/log/ha-debug >> logfile /var/log/ha-log >> logfacility local0 >> keepalive 2 >> deadtime 30 >> warntime 10 >> initdead 120 >> baud 19200 >> serial/dev/ttyS0 >> auto_failback on >> node host1 host2 >> ping ゲートウェアIP >> respawn hacluster /usr/lib/haertbeat/ipfail >> apiauth ipfail gid=haclient uid=hacluster ※host1のみ >> ------------------------ >> >> 事象 >> Webサーバ×2台のクラスタ構成で、Webアクセス不可となりました。 >> ログ解析の結果、host2にはかなりの負荷が発生しており、ハートビートライン >> のアップダウンを繰り返していたようです。 >> ※障害対応は別担当者であったため報告内容と作業ログのみで把握しています。 >> >> 質問 >> 1.Heartbert内部エラー?が発生し、その後30回繰り返した後、緊急停止し >> ていたように見えます。 >> この内部エラー?はどのような不具合なのでしょうか >> >> 2.Heartbertが緊急停止する条件とはどんな時なのでしょうか >> >> >> お手数ですが、宜しくお願いします。 >> >> >> >> 以下、全てhost1のログになります。 >> >> ○内部エラー?ログ >> ha-debug ================================================== >> host1 heartbeat: [10560]: WARN: ha_msg_add_nv_depth: line doesn't >> contain '=' >> host1 heartbeat: [10560]: info: >>> >> host1 heartbeat: [10560]: ERROR: NV failure (msgfromsteam): [>>> ] >> host1 heartbeat: [10578]: info: Local Resource acquisition completed. >> host1 heartbeat: [10577]: info: Local Resource acquisition completed. >> host1 harc[10681]: info: Running /etc/ha.d/rc.d/status status >> host1 mach_down[10691]: info: /usr/lib/heartbeat/mach_down: >> nice_failback: foreign resources acquired >> host1 mach_down[10691]: info: mach_down takeover complete for node host2. >> host1 heartbeat: [10558]: info: Comm_now_up(): updating status to active >> host1 heartbeat: [10558]: info: Local status now set to: 'active' >> host1 heartbeat: [10558]: info: Starting child client >> "/usr/lib/heartbeat/ipfail" (23360,23360) >> host1 heartbeat: [10719]: info: Starting "/usr/lib/heartbeat/ipfail" as >> uid 23360 gid 23360 (pid 10719) >> >> ○繰り返しログ >> ha-debug ================================================== >> host1 heartbeat: [10558]: CRIT: Cluster node host2 returning after >> partition. >> host1 heartbeat: [10558]: info: For information on cluster partitions, >> See URL: http://linux-ha.org/SplitBrain >> host1 heartbeat: [10558]: WARN: Deadtime value may be too small. >> host1 heartbeat: [10558]: info: See FAQ for information on tuning >> > deadtime. > >> host1 heartbeat: [10558]: info: URL: http://linux-ha.org/FAQ#heavy_load >> host1 heartbeat: [10558]: info: Link host2:/dev/ttyS0 up. >> host1 heartbeat: [10558]: WARN: Late heartbeat: Node host2: interval >> 111990 ms >> host1 heartbeat: [10558]: info: Status update for node host2: status >> > active > >> host1 ipfail: [10719]: info: Link Status update: Link host2//dev/ttyS0 >> now has status up >> host1 ipfail: [10719]: info: Status update: Node host2 now has status >> > active > >> host1 harc[10720]: info: Running /etc/ha.d/rc.d/status status >> host1 heartbeat: [10558]: info: all clients are now paused >> host1 heartbeat: [10558]: WARN: Shutdown delayed until current resource >> activity finishes. >> >> host1 heartbeat: [10558]: WARN: node host2: is dead >> host1 heartbeat: [10558]: info: Dead node host2 gave up resources. >> host1 ipfail: [10719]: info: Status update: Node host2 now has status dead >> host1 heartbeat: [10558]: info: all clients are now resumed >> host1 heartbeat: [10558]: info: Link host2:/dev/ttyS0 dead. >> host1 ipfail: [10719]: info: NS: We are still alive! >> host1 ipfail: [10719]: info: Link Status update: Link host2//dev/ttyS0 >> now has status dead >> host1 ipfail: [10719]: info: Asking other side for ping node count. >> host1 ipfail: [10719]: info: Checking remote count of ping nodes. >> ========================================================== >> >> ○緊急停止ログ >> ha-debug ================================================== >> host1 heartbeat: [10558]: CRIT: Emergency Shutdown: Attempting to kill >> everything ourselves >> ========================================================== >> >> _______________________________________________ >> Linux-ha-japan mailing list >> Linux****@lists***** >> http://lists.sourceforge.jp/mailman/listinfo/linux-ha-japan >> >> ------------------------------------------------------------------------ >> >> _______________________________________________ >> Linux-ha-japan mailing list >> Linux****@lists***** >> http://lists.sourceforge.jp/mailman/listinfo/linux-ha-japan >>