wataru yamamoto
wyama****@kke*****
2011年 11月 3日 (木) 16:09:10 JST
Fork松島様
山本です。
ご回答ありがとうございます。
> ifdownしたのはhostM1ということでよろしいでしょうか？
そうです。
> ふと思ったのですが、Router 1とRouter 2は同じネットワークセグメントなのですね。
> VIPとその獲得、パケットをどのインターフェイスから出すか、routeなどでシステムが混乱しているのかも
> しれません（知識の裏付けが私にはありません）。
すみません。ネットワークアドレスを記述していませんでした。
同一セグメントではありません。
・Router1側のネットワークアドレスは、aa.bb.cc.240/29
・Router2側のネットワークアドレスは、aa.bb.cc.192/28
となります。
図にも追記してみました。何度もすみません。
+---------+
| Router1 |
+---------+
(aa.bb.cc.241/29)
|
netaddr |
(aa.bb.cc.240/29) |
|
+---------仮想IP1------+
| (aa.bb.cc.242/29) |
| |
| |
eth2 eth2
(aa.bb.cc.243/29) (aa.bb.cc.244/29)
+--------+ +--------+ (dd.ee.ff.1/28)
eth3| |eth1 eth1| |eth3 +---------+
+-----| hostM1 |-------------| hostB1 |--------+----| |
| | | | | | | Router3 |
| +--------+ +--------+ | | |
| (aa.bb.cc.202/28) (aa.bb.cc.203/28) | +---------+
| eth0 eth0 |
| | | |
| | (aa.bb.cc.201/28) | |
| +---------仮想IP2------+ |
| | |
| netaddr | | netaddr
| (aa.bb.cc.192/28)| |(dd.ee.ff.0/28)
| | |
| (aa.bb.cc.193/28) |
| +---------+ |
| | Router2 | |
| +---------+ |
| |
+----------------------------------------------+
仮に、aa.bb.ccが1.2.3だとすると、
・Router1側のネットワークアドレスと使用可能なIPアドレスは、
1.2.3.240/29、1.2.3.241〜1.2.3.246
・Router2側のネットワークアドレスと使用可能なIPアドレスは、
1.2.3.192/28、1.2.3.192.193〜1.2.3.192.206
となり、問題ないように思えます。(私、この計算苦手なのですが)
実は当初、お客様からRouter1,2を同一ネットワークアドレスで
やってほしいとの要望がありました。一応それでも動いたのを少しだけ
確認したのですが、やっぱりリスキーに思えたので、このようにセグメント
をわけてもった次第です。セグメントの値はお客様が決めました。
ちなみに今回の問題が発生した時に、仮想IP2をつぶして仮想IP1だけに
しても、同じ現象でした。
> ifdown eth2してeth3からの返事もなくなっているのが不思議ですね。
そうなんです。
> ifdown eth2をhostM1でやっていたら、hostM1からRouter1には到達できないのでは、
ううぅ、まさしくその通りです。ここからのRouter1とのpingの様子は、hostM1でなく
フェールオーバ先のhostB1のログを参照すべきでした！大間抜けですみません！
以降にフェールオーバ直後と思われるhostB1のログを示します。例によって匿名化して、
<<point b1>>,<<point b2>>,<<point b3>>を入れています。
-------- ha-log failover err @ hostB1 start -----------
Nov 2 10:02:42 hostB1 attrd: [30546]: info: attrd_ha_callback: flush message from hostm1
Nov 2 10:02:42 hostB1 attrd: [30546]: info: find_hash_entry: Creating hash entry for fail-count-ip-s
Nov 2 10:02:42 hostB1 attrd: [30546]: info: attrd_ha_callback: flush message from hostm1
Nov 2 10:02:42 hostB1 attrd: [30546]: info: find_hash_entry: Creating hash entry for last-failure-ip-s
Nov 2 10:04:07 hostB1 attrd: [30546]: info: attrd_ha_callback: flush message from hostm1
Nov 2 10:04:07 hostB1 crmd: [30547]: info: do_lrm_rsc_op: Performing
key=11:8:0:db95561c-6613-41e2-b7a0-17b8701178c3 op=ip-g_start_0 )
Nov 2 10:04:07 hostB1 lrmd: [30544]: info: rsc:ip-g:8: start
<<point b1>>
Nov 2 10:04:07 hostB1 IPaddr2[30799]: INFO: ip -f inet addr add aa.bb.cc.201/28 brd aa.bb.cc.207
dev eth0
Nov 2 10:04:07 hostB1 IPaddr2[30799]: INFO: ip link set eth0 up
Nov 2 10:04:07 hostB1 IPaddr2[30799]: INFO: /usr/lib64/heartbeat/send_arp -i 200 -r 5 -p
/var/run/heartbeat/rsctmp/send_arp-aa.bb.cc.201 eth0 aa.bb.cc.201 auto not_used not_used
Nov 2 10:04:07 hostB1 crmd: [30547]: info: process_lrm_event: LRM operation ip-g_start_0 (call=8,
rc=0, cib-update=20, confirmed=true) ok
Nov 2 10:04:08 hostB1 crmd: [30547]: info: do_lrm_rsc_op: Performing
key=12:8:0:db95561c-6613-41e2-b7a0-17b8701178c3 op=ip-g_monitor_10000 )
Nov 2 10:04:08 hostB1 lrmd: [30544]: info: rsc:ip-g:9: monitor
Nov 2 10:04:08 hostB1 crmd: [30547]: info: do_lrm_rsc_op: Performing
key=14:8:0:db95561c-6613-41e2-b7a0-17b8701178c3 op=ip-s_start_0 )
Nov 2 10:04:08 hostB1 lrmd: [30544]: info: rsc:ip-s:10: start
Nov 2 10:04:08 hostB1 crmd: [30547]: info: process_lrm_event: LRM operation ip-g_monitor_10000
(call=9, rc=0, cib-update=21, confirmed=false) ok
<<point b2>>
Nov 2 10:04:08 hostB1 IPaddr2[30858]: INFO: ip -f inet addr add aa.bb.cc.242/29 brd aa.bb.cc.247
dev eth2
Nov 2 10:04:08 hostB1 IPaddr2[30858]: INFO: ip link set eth2 up
Nov 2 10:04:08 hostB1 IPaddr2[30858]: INFO: /usr/lib64/heartbeat/send_arp -i 200 -r 5 -p
/var/run/heartbeat/rsctmp/send_arp-aa.bb.cc.242 eth2 aa.bb.cc.242 auto not_used not_used
Nov 2 10:04:08 hostB1 crmd: [30547]: info: process_lrm_event: LRM operation ip-s_start_0 (call=10,
rc=0, cib-update=22, confirmed=true) ok
Nov 2 10:04:09 hostB1 crmd: [30547]: info: do_lrm_rsc_op: Performing
key=15:8:0:db95561c-6613-41e2-b7a0-17b8701178c3 op=ip-s_monitor_10000 )
Nov 2 10:04:09 hostB1 lrmd: [30544]: info: rsc:ip-s:11: monitor
Nov 2 10:04:09 hostB1 crmd: [30547]: info: do_lrm_rsc_op: Performing
key=17:8:0:db95561c-6613-41e2-b7a0-17b8701178c3 op=hoge-r_start_0 )
Nov 2 10:04:09 hostB1 lrmd: [30544]: info: rsc:hoge-r:12: start
Nov 2 10:04:09 hostB1 hoge_proxy.ra[30942]: INFO: Starting hoge_proxy ...
Nov 2 10:04:09 hostB1 crmd: [30547]: info: process_lrm_event: LRM operation ip-s_monitor_10000
(call=11, rc=0, cib-update=23, confirmed=false) ok
Nov 2 10:04:10 hostB1 hoge_proxy.ra[30942]: INFO: hoge_proxy started
Nov 2 10:04:10 hostB1 crmd: [30547]: info: process_lrm_event: LRM operation hoge-r_start_0
(call=12, rc=0, cib-update=24, confirmed=true) ok
Nov 2 10:04:11 hostB1 crmd: [30547]: info: do_lrm_rsc_op: Performing
key=18:8:0:db95561c-6613-41e2-b7a0-17b8701178c3 op=hoge-r_monitor_15000 )
Nov 2 10:04:11 hostB1 lrmd: [30544]: info: rsc:hoge-r:13: monitor
Nov 2 10:04:11 hostB1 crmd: [30547]: info: process_lrm_event: LRM operation hoge-r_monitor_15000
(call=13, rc=0, cib-update=25, confirmed=false) ok
Nov 2 10:04:11 hostB1 lrmd: [30544]: info: RA output: (ip-g:start:stderr) ARPING aa.bb.cc.201 from
aa.bb.cc.201 eth0#012Sent 5 probes (5 broadcast(s))#012Received 0 response(s)
Nov 2 10:04:12 hostB1 lrmd: [30544]: info: RA output: (ip-s:start:stderr) ARPING aa.bb.cc.242 from
aa.bb.cc.242 eth2#012Sent 5 probes (5 broadcast(s))#012Received 0 response(s)
Nov 2 10:04:13 hostB1 attrd: [30546]: info: attrd_ha_callback: flush message from hostm1
Nov 2 10:04:19 hostB1 attrd: [30546]: info: attrd_ha_callback: flush message from hostm1
<<point b3>>
Nov 2 10:04:30 hostB1 heartbeat: [30529]: info: Link hostm1:eth3 dead.
Nov 2 10:04:41 hostB1 attrd: [30546]: info: attrd_ha_callback: flush message from hostm1
Nov 2 10:06:38 hostB1 attrd: [30546]: info: attrd_ha_callback: flush message from hostm1
Nov 2 10:06:38 hostB1 crmd: [30547]: notice: crmd_client_status_callback: Status update: Client
hostm1/crmd now has status [offline] (DC=false)
Nov 2 10:06:38 hostB1 crmd: [30547]: info: crm_update_peer_proc: hostm1.crmd is now offline
Nov 2 10:06:38 hostB1 crmd: [30547]: info: crmd_client_status_callback: Got client status callback
- our DC is dead
Nov 2 10:06:38 hostB1 crmd: [30547]: info: do_state_transition: State transition S_NOT_DC ->
S_ELECTION [ input=I_ELECTION cause=C_CRMD_STATUS_CALLBACK origin=crmd_client_status_callback ]
Nov 2 10:06:38 hostB1 crmd: [30547]: info: update_dc: Unset DC hostm1
Nov 2 10:06:38 hostB1 cib: [30543]: info: cib_process_shutdown_req: Shutdown REQ from hostm1
Nov 2 10:06:38 hostB1 cib: [30543]: info: cib_process_request: Operation complete: op
cib_shutdown_req for section 'all' (origin=hostm1/hostm1/(null), version=0.7.62): ok (rc=0)
Nov 2 10:06:39 hostB1 crmd: [30547]: info: mem_handle_event: Got an event OC_EV_MS_NOT_PRIMARY from ccm
Nov 2 10:06:39 hostB1 crmd: [30547]: info: mem_handle_event: instance=2, nodes=2, new=2, lost=0,
n_idx=0, new_idx=0, old_idx=4
Nov 2 10:06:39 hostB1 crmd: [30547]: info: crmd_ccm_msg_callback: Quorum lost after event=NOT
PRIMARY (id=2)
Nov 2 10:06:39 hostB1 cib: [30543]: info: cib_client_status_callback: Status update: Client
hostm1/cib now has status [leave]
Nov 2 10:06:39 hostB1 cib: [30543]: info: crm_update_peer_proc: hostm1.cib is now offline
Nov 2 10:06:39 hostB1 cib: [30543]: info: mem_handle_event: Got an event OC_EV_MS_NOT_PRIMARY from ccm
Nov 2 10:06:39 hostB1 cib: [30543]: info: mem_handle_event: instance=2, nodes=2, new=2, lost=0,
n_idx=0, new_idx=0, old_idx=4
Nov 2 10:06:39 hostB1 cib: [30543]: info: cib_ccm_msg_callback: Processing CCM event=NOT PRIMARY (id=2)
Nov 2 10:06:49 hostB1 heartbeat: [30529]: info: killing /usr/lib64/heartbeat/crmd process group
30547 with signal 15
Nov 2 10:06:49 hostB1 crmd: [30547]: info: crm_signal_dispatch: Invoking handler for signal 15:
Terminated
Nov 2 10:06:49 hostB1 crmd: [30547]: info: crm_shutdown: Requesting shutdown
Nov 2 10:06:49 hostB1 crmd: [30547]: info: do_shutdown_req: Sending shutdown request to DC: <null>
Nov 2 10:06:49 hostB1 ccm: [30542]: debug: quorum plugin: majority
Nov 2 10:06:49 hostB1 ccm: [30542]: debug: cluster:linux-ha, member_count=1, member_quorum_votes=100
Nov 2 10:06:49 hostB1 ccm: [30542]: debug: total_node_count=2, total_quorum_votes=200
Nov 2 10:06:49 hostB1 ccm: [30542]: debug: quorum plugin: twonodes
Nov 2 10:06:49 hostB1 ccm: [30542]: debug: cluster:linux-ha, member_count=1, member_quorum_votes=100
Nov 2 10:06:49 hostB1 ccm: [30542]: debug: total_node_count=2, total_quorum_votes=200
Nov 2 10:06:49 hostB1 ccm: [30542]: info: Break tie for 2 nodes cluster
Nov 2 10:06:49 hostB1 crmd: [30547]: info: mem_handle_event: Got an event OC_EV_MS_INVALID from ccm
Nov 2 10:06:49 hostB1 crmd: [30547]: info: mem_handle_event: no mbr_track info
Nov 2 10:06:49 hostB1 crmd: [30547]: info: mem_handle_event: Got an event OC_EV_MS_NEW_MEMBERSHIP
from ccm
Nov 2 10:06:49 hostB1 crmd: [30547]: info: mem_handle_event: instance=3, nodes=1, new=0, lost=1,
n_idx=0, new_idx=1, old_idx=3
Nov 2 10:06:49 hostB1 crmd: [30547]: info: crmd_ccm_msg_callback: Quorum (re)attained after
event=NEW MEMBERSHIP (id=3)
Nov 2 10:06:49 hostB1 crmd: [30547]: info: ccm_event_detail: NEW MEMBERSHIP: trans=3, nodes=1,
new=0, lost=1 n_idx=0, new_idx=1, old_idx=3
Nov 2 10:06:49 hostB1 crmd: [30547]: info: ccm_event_detail: #011CURRENT: hostb1 [nodeid=0, born=3]
Nov 2 10:06:49 hostB1 crmd: [30547]: info: ccm_event_detail: #011LOST: hostm1 [nodeid=1, born=1]
Nov 2 10:06:49 hostB1 crmd: [30547]: info: crm_update_peer: Node hostm1: id=1 state=lost (new)
addr=(null) votes=-1 born=1 seen=2 proc=00000000000000000000000000000002
Nov 2 10:06:49 hostB1 cib: [30543]: info: mem_handle_event: Got an event OC_EV_MS_INVALID from ccm
Nov 2 10:06:49 hostB1 cib: [30543]: info: mem_handle_event: no mbr_track info
Nov 2 10:06:49 hostB1 cib: [30543]: info: mem_handle_event: Got an event OC_EV_MS_NEW_MEMBERSHIP
from ccm
Nov 2 10:06:49 hostB1 cib: [30543]: info: mem_handle_event: instance=3, nodes=1, new=0, lost=1,
n_idx=0, new_idx=1, old_idx=3
Nov 2 10:06:49 hostB1 cib: [30543]: info: cib_ccm_msg_callback: Processing CCM event=NEW MEMBERSHIP
(id=3)
Nov 2 10:06:49 hostB1 crmd: [30547]: info: do_state_transition: State transition S_ELECTION ->
S_INTEGRATION [ input=I_ELECTION_DC cause=C_FSA_INTERNAL origin=do_election_check ]
Nov 2 10:06:49 hostB1 cib: [30543]: info: crm_update_peer: Node hostm1: id=1 state=lost (new)
addr=(null) votes=-1 born=1 seen=2 proc=00000000000000000000000000000202
Nov 2 10:06:49 hostB1 crmd: [30547]: info: do_te_control: Registering TE UUID:
91485bad-0cc7-4a69-8dc5-6b3880de3067
Nov 2 10:06:49 hostB1 crmd: [30547]: info: set_graph_functions: Setting custom graph functions
Nov 2 10:06:49 hostB1 crmd: [30547]: info: unpack_graph: Unpacked transition -1: 0 actions in 0
synapses
Nov 2 10:06:49 hostB1 crmd: [30547]: info: start_subsystem: Starting sub-system "pengine"
Nov 2 10:06:49 hostB1 pengine: [32308]: info: Invoked: /usr/lib64/heartbeat/pengine
Nov 2 10:06:49 hostB1 pengine: [32308]: info: main: Starting pengine
-------- ha-log failover err @ hostB1 end -------------
確かに、<<point b1>>, <<point b2>>で、eth0,eth2それぞれにip割り当ててarp
出してますね。勉強になります。やっぱりきちんとログみないとだめですね。
ありがとうございます。
ただ<<point b3>>で、
>Nov 2 10:04:30 hostB1 heartbeat: [30529]: info: Link hostm1:eth3 dead.
とhostm1のeth3が死んでしまっています。先ほどのhostM1のログや、松島さんの指摘にも
ありますとおり、これが原因なのでしょうか？でもフェールオーバしてしまった
ホストのI/Fなので、これはこれでもよいものなのかな？？
ちなみに、図でも示しているようにeth3サイドについてはお客さんの要望で仮想IP
を設けていません。もしかして仮想IPは全I/Fに設定しておいた方がよいのかな？
さらにpingdもそれに合わせておいたほうがよいのかな？
でも、そもそもeth0を抜いた時にはきれいにフェールオーバーしている。eth3も
同様。なぜeth2だけが？？
なんだかよくわからなくなってきました。現場できちんとログを取り直す必要があると思います。
ちなみに同ログをERRORでgrepすると以下のようなものが出ます。
-----------------------------------------------------------------
Nov 2 10:23:09 hostB1 pengine: [4037]: ERROR: unpack_resources: Resource start-up disabled since no
STONITH resources have been defined
Nov 2 10:23:09 hostB1 pengine: [4037]: ERROR: unpack_resources: Either configure some or disable
STONITH with the stonith-enabled option
Nov 2 10:23:09 hostB1 pengine: [4037]: ERROR: unpack_resources: NOTE: Clusters with shared data
need STONITH to ensure data integrity
-----------------------------------------------------------------
STONITHってよくわからず設定も面倒でしたので、使わないよう設定していたと思いますが、
これもなにか関係ありそうでしょうか。
またなにか思い出した時にでも構いません。よろしくお願いいたします。
以上です。
--
yamamoto