
hayato at starsystems
Jan 11, 2012, 7:49 PM
Post #6 of 11
(530 views)
Permalink
|
$B9uLZMM(B $BCSEDMM(B $B$*@$OC$K$J$j$^$9!#(B $B<D5\$G$9!#(B $BCSEDMM$+$i$N$4Ds<($5$l$?@_Dj$rN.$79~$_(B $B:FEY!"(Bnode1$B$N(BHeartbeat$B%W%m%;%9$rMn$H$9(B $B;n83$r9T$$$^$7$?$,!">u67$KJQ2=$"$j$^$;(B $B$s$G$7$?!#(B $B"(0l=V(Bnode2$BB&$,(Bprimary$B$K$J$k$N$b0l=o$G$9(B $B0J2<!"%m%0$rH4?h$5$;$FD:$-$^$9$N$G!"(B $B$*<j?t$r$*3]$1CW$7$^$9$,!"$465<x$NDx!"(B $B59$7$/$*4j$$CW$7$^$9!#(B $B"(BgNL$N%m%0$G!"?=$7Lu$"$j$^$;$s!#(B $B!c%m%0!d(B Jan 12 11:31:25 node2 pengine: [3735]: notice: clone_print: Master/Slave Set: ms_drbd Jan 12 11:31:25 node2 pengine: [3735]: notice: short_print: Masters: [ node1 ] Jan 12 11:31:25 node2 pengine: [3735]: notice: short_print: Slaves: [ node2 ] Jan 12 11:31:25 node2 pengine: [3735]: info: native_color: Resource drbd_hadoop:1 cannot run anywhere Jan 12 11:31:25 node2 pengine: [3735]: info: master_color: Promoting drbd_hadoop:0 (Slave node2) Jan 12 11:31:25 node2 pengine: [3735]: info: master_color: ms_drbd: Promoted 1 instances of a possible 1 to master Jan 12 11:31:25 node2 pengine: [3735]: notice: RecurringOp: Start recurring monitor (10s) for drbd_hadoop:0 on node2 Jan 12 11:31:25 node2 pengine: [3735]: info: RecurringOp: Cancelling action drbd_hadoop:0_monitor_20000 (Slave vs. Master) Jan 12 11:31:25 node2 pengine: [3735]: notice: RecurringOp: Start recurring monitor (10s) for drbd_hadoop:0 on node2 Jan 12 11:31:25 node2 pengine: [3735]: info: RecurringOp: Cancelling action drbd_hadoop:0_monitor_20000 (Slave vs. Master) Jan 12 11:31:25 node2 pengine: [3735]: info: stage6: Scheduling Node node1 for shutdown Jan 12 11:31:25 node2 pengine: [3735]: notice: LogActions: Promote drbd_hadoop:0 (Slave -> Master node2) Jan 12 11:31:25 node2 pengine: [3735]: notice: LogActions: Demote drbd_hadoop:1 (Master -> Stopped node1) Jan 12 11:31:25 node2 pengine: [3735]: notice: LogActions: Stop resource drbd_hadoop:1 (node1) Jan 12 11:31:25 node2 pengine: [3735]: info: process_pe_message: Transition 3: PEngine Input stored in: /var/lib/pengine/pe-input-1520.bz2 Jan 12 11:31:25 node2 crmd: [3731]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ] Jan 12 11:31:25 node2 crmd: [3731]: info: unpack_graph: Unpacked transition 3: 34 actions in 34 synapses Jan 12 11:31:25 node2 crmd: [3731]: info: do_te_invoke: Processing graph 3 (ref=pe_calc-dc-1326335485-33) derived from /var/lib/pengine/pe-input-1520.bz2 Jan 12 11:31:25 node2 crmd: [3731]: info: te_rsc_command: Initiating action 2: cancel drbd_hadoop:0_monitor_20000 on node2 (local) Jan 12 11:31:25 node2 lrmd: [3728]: info: cancel_op: operation monitor[5] on ocf::drbd::drbd_hadoop:0 for client 3731, its parameters: CRM_meta_interval=[20000] CRM_meta_role=[Slave] drbdconf=[/etc/drbd.conf] drbd_resource=[r0] CRM_meta_master_max=[1] CRM_meta_on_fail=[restart] CRM_meta_timeout=[20000] CRM_meta_clone_max=[2] CRM_meta_master_node_max=[1] crm_feature_set=[3.0.1] CRM_meta_globally_unique=[false] CRM_meta_name=[monitor] CRM_meta_clone=[0] CRM_meta_clone_node_max=[1] CRM_meta_notify=[true] cancelled Jan 12 11:31:25 node2 crmd: [3731]: info: send_direct_ack: ACK'ing resource op drbd_hadoop:0_monitor_20000 from 2:3:0:3ab7eec5-827b-4fa1-b137-65c9363ad006: lrm_invoke-lrmd-1326335485-35 Jan 12 11:31:25 node2 crmd: [3731]: info: process_te_message: Processing (N)ACK lrm_invoke-lrmd-1326335485-35 from node2 Jan 12 11:31:25 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_monitor_20000 (2) confirmed on node2 (rc=0) Jan 12 11:31:25 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 34 fired and confirmed Jan 12 11:31:25 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_monitor_20000 (call=5, status=1, cib-update=0, confirmed=true) Cancelled Jan 12 11:31:25 node2 crmd: [3731]: info: te_rsc_command: Initiating action 50: notify drbd_hadoop:0_pre_notify_demote_0 on node2 (local) Jan 12 11:31:25 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=50:3:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_notify_0 ) Jan 12 11:31:25 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:6: notify Jan 12 11:31:25 node2 crmd: [3731]: info: te_rsc_command: Initiating action 52: notify drbd_hadoop:1_pre_notify_demote_0 on node1 Jan 12 11:31:25 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_notify_0 (call=6, rc=0, cib-update=57, confirmed=true) ok Jan 12 11:31:25 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_pre_notify_demote_0 (50) confirmed on node2 (rc=0) Jan 12 11:31:27 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:1_pre_notify_demote_0 (52) confirmed on node1 (rc=0) Jan 12 11:31:27 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 35 fired and confirmed Jan 12 11:31:27 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 32 fired and confirmed Jan 12 11:31:27 node2 crmd: [3731]: info: te_rsc_command: Initiating action 12: demote drbd_hadoop:1_demote_0 on node1 Jan 12 11:31:27 node2 kernel: block drbd0: peer( Primary -> Secondary ) Jan 12 11:31:28 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:1_demote_0 (12) confirmed on node1 (rc=0) Jan 12 11:31:28 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 33 fired and confirmed Jan 12 11:31:28 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 36 fired and confirmed Jan 12 11:31:28 node2 crmd: [3731]: info: te_rsc_command: Initiating action 51: notify drbd_hadoop:0_post_notify_demote_0 on node2 (local) Jan 12 11:31:28 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=51:3:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_notify_0 ) Jan 12 11:31:28 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:7: notify Jan 12 11:31:28 node2 crmd: [3731]: info: te_rsc_command: Initiating action 53: notify drbd_hadoop:1_post_notify_demote_0 on node1 Jan 12 11:31:28 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:notify:stdout) Jan 12 11:31:28 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_notify_0 (call=7, rc=0, cib-update=58, confirmed=true) ok Jan 12 11:31:28 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_post_notify_demote_0 (51) confirmed on node2 (rc=0) Jan 12 11:31:30 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:1_post_notify_demote_0 (53) confirmed on node1 (rc=0) Jan 12 11:31:30 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 37 fired and confirmed Jan 12 11:31:30 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 22 fired and confirmed Jan 12 11:31:30 node2 crmd: [3731]: info: te_rsc_command: Initiating action 45: notify drbd_hadoop:0_pre_notify_stop_0 on node2 (local) Jan 12 11:31:30 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=45:3:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_notify_0 ) Jan 12 11:31:30 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:8: notify Jan 12 11:31:30 node2 crmd: [3731]: info: te_rsc_command: Initiating action 47: notify drbd_hadoop:1_pre_notify_stop_0 on node1 Jan 12 11:31:30 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_notify_0 (call=8, rc=0, cib-update=59, confirmed=true) ok Jan 12 11:31:30 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_pre_notify_stop_0 (45) confirmed on node2 (rc=0) Jan 12 11:31:32 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:1_pre_notify_stop_0 (47) confirmed on node1 (rc=0) Jan 12 11:31:32 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 23 fired and confirmed Jan 12 11:31:32 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 20 fired and confirmed Jan 12 11:31:32 node2 crmd: [3731]: info: te_rsc_command: Initiating action 13: stop drbd_hadoop:1_stop_0 on node1 Jan 12 11:31:33 node2 kernel: block drbd0: peer( Secondary -> Unknown ) conn( Connected -> TearDown ) pdsk( UpToDate -> DUnknown ) Jan 12 11:31:33 node2 kernel: block drbd0: meta connection shut down by peer. Jan 12 11:31:33 node2 kernel: block drbd0: asender terminated Jan 12 11:31:33 node2 kernel: block drbd0: Terminating asender thread Jan 12 11:31:33 node2 kernel: block drbd0: Connection closed Jan 12 11:31:33 node2 kernel: block drbd0: conn( TearDown -> Unconnected ) Jan 12 11:31:33 node2 kernel: block drbd0: receiver terminated Jan 12 11:31:33 node2 kernel: block drbd0: Restarting receiver thread Jan 12 11:31:33 node2 kernel: block drbd0: receiver (re)started Jan 12 11:31:33 node2 kernel: block drbd0: conn( Unconnected -> WFConnection ) Jan 12 11:31:34 node2 attrd: [3730]: info: attrd_ha_callback: flush message from node1 Jan 12 11:31:34 node2 crmd: [3731]: info: abort_transition_graph: te_update_diff:164 - Triggered transition abort (complete=0, tag=transient_attributes, id=d70cae93-bce1-4389-808f-facb2ce776f4, magic=NA, cib=0.8.27) : Transient attribute: removal Jan 12 11:31:34 node2 crmd: [3731]: info: update_abort_priority: Abort priority upgraded from 0 to 1000000 Jan 12 11:31:34 node2 crmd: [3731]: info: update_abort_priority: Abort action done superceeded by restart Jan 12 11:31:34 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:1_stop_0 (13) confirmed on node1 (rc=0) Jan 12 11:31:34 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 21 fired and confirmed Jan 12 11:31:34 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 24 fired and confirmed Jan 12 11:31:34 node2 crmd: [3731]: info: te_rsc_command: Initiating action 46: notify drbd_hadoop:0_post_notify_stop_0 on node2 (local) Jan 12 11:31:34 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=46:3:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_notify_0 ) Jan 12 11:31:34 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:9: notify Jan 12 11:31:34 node2 attrd: [3730]: info: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_hadoop:0 (1000) Jan 12 11:31:34 node2 attrd: [3730]: info: attrd_perform_update: Sent update 20: master-drbd_hadoop:0=1000 Jan 12 11:31:34 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:notify:stdout) Jan 12 11:31:34 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_notify_0 (call=9, rc=0, cib-update=60, confirmed=true) ok Jan 12 11:31:34 node2 crmd: [3731]: info: abort_transition_graph: te_update_diff:150 - Triggered transition abort (complete=0, tag=nvpair, id=status-0a6c069f-e618-4f5b-a7b4-4ba53e5ff890-master-drbd_hadoop:0, name=NA, value=1000, magic=NA, cib=0.8.29) : Transient attribute: update Jan 12 11:31:34 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_post_notify_stop_0 (46) confirmed on node2 (rc=0) Jan 12 11:31:34 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 25 fired and confirmed Jan 12 11:31:34 node2 crmd: [3731]: info: run_graph: ==================================================== Jan 12 11:31:34 node2 crmd: [3731]: notice: run_graph: Transition 3 (Complete=22, Pending=0, Fired=0, Skipped=8, Incomplete=4, Source=/var/lib/pengine/pe-input-1520.bz2): Stopped Jan 12 11:31:34 node2 crmd: [3731]: info: te_graph_trigger: Transition 3 is now complete Jan 12 11:31:36 node2 crmd: [3731]: info: crm_timer_popped: New Transition Timer (I_PE_CALC) just popped! Jan 12 11:31:36 node2 crmd: [3731]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_TIMER_POPPED origin=crm_timer_popped ] Jan 12 11:31:36 node2 crmd: [3731]: info: do_state_transition: Progressed to state S_POLICY_ENGINE after C_TIMER_POPPED Jan 12 11:31:36 node2 crmd: [3731]: info: do_state_transition: All 2 cluster nodes are eligible to run resources. Jan 12 11:31:36 node2 crmd: [3731]: info: do_pe_invoke: Query 61: Requesting the current CIB: S_POLICY_ENGINE Jan 12 11:31:36 node2 crmd: [3731]: info: do_pe_invoke_callback: Invoking the PE: query=61, ref=pe_calc-dc-1326335496-45, seq=2, quorate=1 Jan 12 11:31:36 node2 pengine: [3735]: notice: unpack_config: On loss of CCM Quorum: Ignore Jan 12 11:31:36 node2 pengine: [3735]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0 Jan 12 11:31:36 node2 pengine: [3735]: WARN: unpack_nodes: Blind faith: not fencing unseen nodes Jan 12 11:31:36 node2 pengine: [3735]: info: determine_online_status: Node node1 is shutting down Jan 12 11:31:36 node2 pengine: [3735]: info: determine_online_status: Node node2 is online Jan 12 11:31:36 node2 pengine: [3735]: notice: unpack_rsc_op: Operation drbd_hadoop:1_monitor_0 found resource drbd_hadoop:1 active on node1 Jan 12 11:31:36 node2 pengine: [3735]: notice: unpack_rsc_op: Operation drbd_hadoop:0_monitor_0 found resource drbd_hadoop:0 active on node2 Jan 12 11:31:36 node2 pengine: [3735]: notice: clone_print: Master/Slave Set: ms_drbd Jan 12 11:31:36 node2 pengine: [3735]: notice: short_print: Slaves: [ node2 ] Jan 12 11:31:36 node2 pengine: [3735]: notice: short_print: Stopped: [ drbd_hadoop:1 ] Jan 12 11:31:36 node2 pengine: [3735]: info: native_color: Resource drbd_hadoop:1 cannot run anywhere Jan 12 11:31:36 node2 pengine: [3735]: info: master_color: Promoting drbd_hadoop:0 (Slave node2) Jan 12 11:31:36 node2 pengine: [3735]: info: master_color: ms_drbd: Promoted 1 instances of a possible 1 to master Jan 12 11:31:36 node2 pengine: [3735]: notice: RecurringOp: Start recurring monitor (10s) for drbd_hadoop:0 on node2 Jan 12 11:31:36 node2 pengine: [3735]: notice: RecurringOp: Start recurring monitor (10s) for drbd_hadoop:0 on node2 Jan 12 11:31:36 node2 pengine: [3735]: info: stage6: Scheduling Node node1 for shutdown Jan 12 11:31:36 node2 pengine: [3735]: notice: LogActions: Promote drbd_hadoop:0 (Slave -> Master node2) Jan 12 11:31:36 node2 pengine: [3735]: notice: LogActions: Leave resource drbd_hadoop:1 (Stopped) Jan 12 11:31:36 node2 crmd: [3731]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ] Jan 12 11:31:36 node2 crmd: [3731]: WARN: destroy_action: Cancelling timer for action 2 (src=75) Jan 12 11:31:36 node2 crmd: [3731]: info: unpack_graph: Unpacked transition 4: 11 actions in 11 synapses Jan 12 11:31:36 node2 crmd: [3731]: info: do_te_invoke: Processing graph 4 (ref=pe_calc-dc-1326335496-45) derived from /var/lib/pengine/pe-input-1521.bz2 Jan 12 11:31:36 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 24 fired and confirmed Jan 12 11:31:36 node2 crmd: [3731]: info: te_crm_command: Executing crm-event (36): do_shutdown on node1 Jan 12 11:31:36 node2 crmd: [3731]: info: te_rsc_command: Initiating action 45: notify drbd_hadoop:0_pre_notify_promote_0 on node2 (local) Jan 12 11:31:36 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=45:4:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_notify_0 ) Jan 12 11:31:36 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:10: notify Jan 12 11:31:36 node2 pengine: [3735]: info: process_pe_message: Transition 4: PEngine Input stored in: /var/lib/pengine/pe-input-1521.bz2 Jan 12 11:31:36 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_notify_0 (call=10, rc=0, cib-update=62, confirmed=true) ok Jan 12 11:31:36 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_pre_notify_promote_0 (45) confirmed on node2 (rc=0) Jan 12 11:31:36 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 25 fired and confirmed Jan 12 11:31:36 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 22 fired and confirmed Jan 12 11:31:36 node2 crmd: [3731]: info: te_rsc_command: Initiating action 8: promote drbd_hadoop:0_promote_0 on node2 (local) Jan 12 11:31:36 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=8:4:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_promote_0 ) Jan 12 11:31:36 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:11: promote Jan 12 11:31:36 node2 kernel: block drbd0: role( Secondary -> Primary ) Jan 12 11:31:36 node2 kernel: block drbd0: Creating new current UUID Jan 12 11:31:36 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:promote:stdout) Jan 12 11:31:36 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_promote_0 (call=11, rc=0, cib-update=63, confirmed=true) ok Jan 12 11:31:36 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_promote_0 (8) confirmed on node2 (rc=0) Jan 12 11:31:36 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 23 fired and confirmed Jan 12 11:31:36 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 26 fired and confirmed Jan 12 11:31:36 node2 crmd: [3731]: info: te_rsc_command: Initiating action 46: notify drbd_hadoop:0_post_notify_promote_0 on node2 (local) Jan 12 11:31:36 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=46:4:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_notify_0 ) Jan 12 11:31:36 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:12: notify Jan 12 11:31:36 node2 attrd: [3730]: info: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_hadoop:0 (10000) Jan 12 11:31:36 node2 attrd: [3730]: info: attrd_perform_update: Sent update 22: master-drbd_hadoop:0=10000 Jan 12 11:31:36 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:notify:stdout) Jan 12 11:31:36 node2 crmd: [3731]: info: abort_transition_graph: te_update_diff:150 - Triggered transition abort (complete=0, tag=nvpair, id=status-0a6c069f-e618-4f5b-a7b4-4ba53e5ff890-master-drbd_hadoop:0, name=NA, value=10000, magic=NA, cib=0.8.33) : Transient attribute: update Jan 12 11:31:36 node2 crmd: [3731]: info: update_abort_priority: Abort priority upgraded from 0 to 1000000 Jan 12 11:31:36 node2 crmd: [3731]: info: update_abort_priority: Abort action done superceeded by restart Jan 12 11:31:36 node2 kernel: block drbd0: State change failed: Need access to UpToDate data Jan 12 11:31:36 node2 kernel: block drbd0: state = { cs:WFConnection ro:Primary/Unknown ds:UpToDate/DUnknown r--- } Jan 12 11:31:36 node2 kernel: block drbd0: wanted = { cs:WFConnection ro:Primary/Unknown ds:Outdated/DUnknown r--- } Jan 12 11:31:36 node2 drbd[4205]: ERROR: r0: Called drbdadm -c /etc/drbd.conf outdate r0 Jan 12 11:31:36 node2 drbd[4205]: ERROR: r0: Exit code 17 Jan 12 11:31:36 node2 drbd[4205]: ERROR: r0: Command output: Jan 12 11:31:36 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:notify:stdout) Jan 12 11:31:36 node2 attrd: [3730]: info: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_hadoop:0 (-INFINITY) Jan 12 11:31:36 node2 attrd: [3730]: info: attrd_perform_update: Sent update 24: master-drbd_hadoop:0=-INFINITY Jan 12 11:31:36 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:notify:stdout) Jan 12 11:31:36 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_notify_0 (call=12, rc=0, cib-update=64, confirmed=true) ok Jan 12 11:31:36 node2 crmd: [3731]: info: abort_transition_graph: te_update_diff:150 - Triggered transition abort (complete=0, tag=nvpair, id=status-0a6c069f-e618-4f5b-a7b4-4ba53e5ff890-master-drbd_hadoop:0, name=NA, value=-INFINITY, magic=NA, cib=0.8.34) : Transient attribute: update Jan 12 11:31:36 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_post_notify_promote_0 (46) confirmed on node2 (rc=0) Jan 12 11:31:36 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 27 fired and confirmed Jan 12 11:31:36 node2 crmd: [3731]: info: run_graph: ==================================================== Jan 12 11:31:36 node2 crmd: [3731]: notice: run_graph: Transition 4 (Complete=10, Pending=0, Fired=0, Skipped=1, Incomplete=0, Source=/var/lib/pengine/pe-input-1521.bz2): Stopped Jan 12 11:31:36 node2 crmd: [3731]: info: te_graph_trigger: Transition 4 is now complete Jan 12 11:31:37 node2 crmd: [3731]: notice: crmd_client_status_callback: Status update: Client node1/crmd now has status [offline] (DC=true) Jan 12 11:31:37 node2 crmd: [3731]: info: crm_update_peer_proc: node1.crmd is now offline Jan 12 11:31:37 node2 crmd: [3731]: info: erase_node_from_join: Removed node node1 from join calculations: welcomed=0 itegrated=0 finalized=0 confirmed=1 Jan 12 11:31:37 node2 cib: [3727]: info: cib_process_shutdown_req: Shutdown REQ from node1 Jan 12 11:31:37 node2 cib: [3727]: info: cib_process_request: Operation complete: op cib_shutdown_req for section 'all' (origin=node1/node1/(null), version=0.8.36): ok (rc=0) Jan 12 11:31:38 node2 crmd: [3731]: info: crm_timer_popped: New Transition Timer (I_PE_CALC) just popped! Jan 12 11:31:38 node2 crmd: [3731]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_TIMER_POPPED origin=crm_timer_popped ] Jan 12 11:31:38 node2 crmd: [3731]: info: do_state_transition: Progressed to state S_POLICY_ENGINE after C_TIMER_POPPED Jan 12 11:31:38 node2 crmd: [3731]: WARN: do_state_transition: Only 1 of 2 cluster nodes are eligible to run resources - continue 0 Jan 12 11:31:38 node2 crmd: [3731]: info: do_pe_invoke: Query 66: Requesting the current CIB: S_POLICY_ENGINE Jan 12 11:31:38 node2 crmd: [3731]: info: do_pe_invoke_callback: Invoking the PE: query=66, ref=pe_calc-dc-1326335498-50, seq=2, quorate=1 Jan 12 11:31:38 node2 pengine: [3735]: notice: unpack_config: On loss of CCM Quorum: Ignore Jan 12 11:31:38 node2 pengine: [3735]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0 Jan 12 11:31:38 node2 pengine: [3735]: WARN: unpack_nodes: Blind faith: not fencing unseen nodes Jan 12 11:31:38 node2 pengine: [3735]: info: determine_online_status: Node node2 is online Jan 12 11:31:38 node2 pengine: [3735]: notice: unpack_rsc_op: Operation drbd_hadoop:0_monitor_0 found resource drbd_hadoop:0 active on node2 Jan 12 11:31:38 node2 pengine: [3735]: notice: clone_print: Master/Slave Set: ms_drbd Jan 12 11:31:38 node2 pengine: [3735]: notice: short_print: Masters: [ node2 ] Jan 12 11:31:38 node2 pengine: [3735]: notice: short_print: Stopped: [ drbd_hadoop:1 ] Jan 12 11:31:38 node2 pengine: [3735]: info: native_color: Resource drbd_hadoop:1 cannot run anywhere Jan 12 11:31:38 node2 pengine: [3735]: info: master_color: ms_drbd: Promoted 0 instances of a possible 1 to master Jan 12 11:31:38 node2 pengine: [3735]: notice: RecurringOp: Start recurring monitor (20s) for drbd_hadoop:0 on node2 Jan 12 11:31:38 node2 pengine: [3735]: notice: RecurringOp: Start recurring monitor (20s) for drbd_hadoop:0 on node2 Jan 12 11:31:38 node2 pengine: [3735]: notice: LogActions: Demote drbd_hadoop:0 (Master -> Slave node2) Jan 12 11:31:38 node2 pengine: [3735]: notice: LogActions: Leave resource drbd_hadoop:1 (Stopped) Jan 12 11:31:38 node2 crmd: [3731]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ] Jan 12 11:31:38 node2 crmd: [3731]: info: unpack_graph: Unpacked transition 5: 10 actions in 10 synapses Jan 12 11:31:38 node2 crmd: [3731]: info: do_te_invoke: Processing graph 5 (ref=pe_calc-dc-1326335498-50) derived from /var/lib/pengine/pe-input-1522.bz2 Jan 12 11:31:38 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 28 fired and confirmed Jan 12 11:31:38 node2 crmd: [3731]: info: te_rsc_command: Initiating action 44: notify drbd_hadoop:0_pre_notify_demote_0 on node2 (local) Jan 12 11:31:38 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=44:5:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_notify_0 ) Jan 12 11:31:38 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:13: notify Jan 12 11:31:38 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_notify_0 (call=13, rc=0, cib-update=67, confirmed=true) ok Jan 12 11:31:38 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_pre_notify_demote_0 (44) confirmed on node2 (rc=0) Jan 12 11:31:38 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 29 fired and confirmed Jan 12 11:31:38 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 26 fired and confirmed Jan 12 11:31:38 node2 crmd: [3731]: info: te_rsc_command: Initiating action 6: demote drbd_hadoop:0_demote_0 on node2 (local) Jan 12 11:31:38 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=6:5:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_demote_0 ) Jan 12 11:31:38 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:14: demote Jan 12 11:31:38 node2 pengine: [3735]: info: process_pe_message: Transition 5: PEngine Input stored in: /var/lib/pengine/pe-input-1522.bz2 Jan 12 11:31:38 node2 kernel: block drbd0: role( Primary -> Secondary ) Jan 12 11:31:38 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:demote:stdout) Jan 12 11:31:38 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_demote_0 (call=14, rc=0, cib-update=68, confirmed=true) ok Jan 12 11:31:38 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_demote_0 (6) confirmed on node2 (rc=0) Jan 12 11:31:38 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 27 fired and confirmed Jan 12 11:31:38 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 30 fired and confirmed Jan 12 11:31:38 node2 crmd: [3731]: info: te_rsc_command: Initiating action 45: notify drbd_hadoop:0_post_notify_demote_0 on node2 (local) Jan 12 11:31:38 node2 crmd: [3731]: info: do_lrm_rsc_op: Performing key=45:5:0:3ab7eec5-827b-4fa1-b137-65c9363ad006 op=drbd_hadoop:0_notify_0 ) Jan 12 11:31:38 node2 lrmd: [3728]: info: rsc:drbd_hadoop:0:15: notify Jan 12 11:31:38 node2 attrd: [3730]: info: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_hadoop:0 (1000) Jan 12 11:31:38 node2 attrd: [3730]: info: attrd_perform_update: Sent update 26: master-drbd_hadoop:0=1000 Jan 12 11:31:38 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:notify:stdout) Jan 12 11:31:38 node2 crmd: [3731]: info: abort_transition_graph: te_update_diff:150 - Triggered transition abort (complete=0, tag=nvpair, id=status-0a6c069f-e618-4f5b-a7b4-4ba53e5ff890-master-drbd_hadoop:0, name=NA, value=1000, magic=NA, cib=0.8.39) : Transient attribute: update Jan 12 11:31:38 node2 crmd: [3731]: info: update_abort_priority: Abort priority upgraded from 0 to 1000000 Jan 12 11:31:38 node2 crmd: [3731]: info: update_abort_priority: Abort action done superceeded by restart Jan 12 11:31:38 node2 kernel: block drbd0: disk( UpToDate -> Outdated ) Jan 12 11:31:38 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:notify:stdout) Jan 12 11:31:38 node2 attrd: [3730]: info: attrd_trigger_update: Sending flush op to all hosts for: master-drbd_hadoop:0 (-INFINITY) Jan 12 11:31:38 node2 attrd: [3730]: info: attrd_perform_update: Sent update 28: master-drbd_hadoop:0=-INFINITY Jan 12 11:31:38 node2 lrmd: [3728]: info: RA output: (drbd_hadoop:0:notify:stdout) Jan 12 11:31:38 node2 crmd: [3731]: info: process_lrm_event: LRM operation drbd_hadoop:0_notify_0 (call=15, rc=0, cib-update=69, confirmed=true) ok Jan 12 11:31:38 node2 crmd: [3731]: info: abort_transition_graph: te_update_diff:150 - Triggered transition abort (complete=0, tag=nvpair, id=status-0a6c069f-e618-4f5b-a7b4-4ba53e5ff890-master-drbd_hadoop:0, name=NA, value=-INFINITY, magic=NA, cib=0.8.40) : Transient attribute: update Jan 12 11:31:38 node2 crmd: [3731]: info: match_graph_event: Action drbd_hadoop:0_post_notify_demote_0 (45) confirmed on node2 (rc=0) Jan 12 11:31:38 node2 crmd: [3731]: info: te_pseudo_action: Pseudo action 31 fired and confirmed Jan 12 11:31:38 node2 crmd: [3731]: info: run_graph: ==================================================== Jan 12 11:31:38 node2 crmd: [3731]: notice: run_graph: Transition 5 (Complete=9, Pending=0, Fired=0, Skipped=1, Incomplete=0, Source=/var/lib/pengine/pe-input-1522.bz2): Stopped Jan 12 11:31:38 node2 crmd: [3731]: info: te_graph_trigger: Transition 5 is now complete Jan 12 11:31:38 node2 ccm: [3726]: info: Break tie for 2 nodes cluster Jan 12 11:31:38 node2 crmd: [3731]: info: mem_handle_event: Got an event OC_EV_MS_INVALID from ccm Jan 12 11:31:38 node2 crmd: [3731]: info: mem_handle_event: no mbr_track info Jan 12 11:31:38 node2 crmd: [3731]: info: mem_handle_event: Got an event OC_EV_MS_NEW_MEMBERSHIP from ccm Jan 12 11:31:38 node2 crmd: [3731]: info: mem_handle_event: instance=3, nodes=1, new=0, lost=1, n_idx=0, new_idx=1, old_idx=3 Jan 12 11:31:38 node2 crmd: [3731]: info: crmd_ccm_msg_callback: Quorum (re)attained after event=NEW MEMBERSHIP (id=3) Jan 12 11:31:38 node2 crmd: [3731]: info: ccm_event_detail: NEW MEMBERSHIP: trans=3, nodes=1, new=0, lost=1 n_idx=0, new_idx=1, old_idx=3 Jan 12 11:31:38 node2 crmd: [3731]: info: ccm_event_detail: CURRENT: node2 [nodeid=1, born=3] Jan 12 11:31:38 node2 crmd: [3731]: info: ccm_event_detail: LOST: node1 [nodeid=0, born=2] Jan 12 11:31:38 node2 crmd: [3731]: info: ais_status_callback: status: node1 is now lost (was member) Jan 12 11:31:38 node2 crmd: [3731]: info: crm_update_peer: Node node1: id=0 state=lost (new) addr=(null) votes=-1 born=2 seen=2 proc=00000000000000000000000000000002 Jan 12 11:31:38 node2 crmd: [3731]: info: populate_cib_nodes_ha: Requesting the list of configured nodes Jan 12 11:31:38 node2 cib: [3727]: info: cib_client_status_callback: Status update: Client node1/cib now has status [leave] Jan 12 11:31:38 node2 cib: [3727]: info: crm_update_peer_proc: node1.cib is now offline Jan 12 11:31:38 node2 cib: [3727]: info: mem_handle_event: Got an event OC_EV_MS_INVALID from ccm Jan 12 11:31:38 node2 cib: [3727]: info: mem_handle_event: no mbr_track info Jan 12 11:31:38 node2 cib: [3727]: info: mem_handle_event: Got an event OC_EV_MS_NEW_MEMBERSHIP from ccm Jan 12 11:31:38 node2 cib: [3727]: info: mem_handle_event: instance=3, nodes=1, new=0, lost=1, n_idx=0, new_idx=1, old_idx=3 Jan 12 11:31:38 node2 cib: [3727]: info: cib_ccm_msg_callback: Processing CCM event=NEW MEMBERSHIP (id=3) Jan 12 11:31:38 node2 cib: [3727]: info: crm_update_peer: Node node1: id=0 state=lost (new) addr=(null) votes=-1 born=2 seen=2 proc=00000000000000000000000000000202 Jan 12 11:31:38 node2 cib: [3727]: info: cib_process_request: Operation complete: op cib_modify for section nodes (origin=local/crmd/70, version=0.8.41): ok (rc=0) Jan 12 11:31:38 node2 crmd: [3731]: WARN: match_down_event: No match for shutdown action on d70cae93-bce1-4389-808f-facb2ce776f4 Jan 12 11:31:38 node2 crmd: [3731]: info: te_update_diff: Stonith/shutdown of d70cae93-bce1-4389-808f-facb2ce776f4 not matched Jan 12 11:31:38 node2 crmd: [3731]: info: abort_transition_graph: te_update_diff:198 - Triggered transition abort (complete=1, tag=node_state, id=d70cae93-bce1-4389-808f-facb2ce776f4, magic=NA, cib=0.8.42) : Node failure Jan 12 11:31:40 node2 crmd: [3731]: info: crm_timer_popped: New Transition Timer (I_PE_CALC) just popped! Jan 12 11:31:40 node2 crmd: [3731]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_TIMER_POPPED origin=crm_timer_popped ] Jan 12 11:31:40 node2 crmd: [3731]: info: do_state_transition: Progressed to state S_POLICY_ENGINE after C_TIMER_POPPED Jan 12 11:31:40 node2 crmd: [3731]: info: do_state_transition: All 1 cluster nodes are eligible to run resources. Jan 12 11:31:40 node2 crmd: [3731]: info: do_pe_invoke: Query 72: Requesting the current CIB: S_POLICY_ENGINE Jan 12 11:31:40 node2 crmd: [3731]: info: do_pe_invoke_callback: Invoking the PE: query=72, ref=pe_calc-dc-1326335500-55, seq=3, quorate=1 Jan 12 11:31:40 node2 pengine: [3735]: notice: unpack_config: On loss of CCM Quorum: Ignore Jan 12 11:31:40 node2 pengine: [3735]: info: unpack_config: Node scores: 'red' = -INFINITY, 'yellow' = 0, 'green' = 0 Jan 12 11:31:40 node2 pengine: [3735]: WARN: unpack_nodes: Blind faith: not fencing unseen nodes Jan 12 11:31:40 node2 pengine: [3735]: info: determine_online_status: Node node2 is online Jan 12 11:31:40 node2 pengine: [3735]: notice: unpack_rsc_op: Operation drbd_hadoop:0_monitor_0 found resource drbd_hadoop:0 active on node2 Jan 12 11:31:40 node2 pengine: [3735]: notice: clone_print: Master/Slave Set: ms_drbd Jan 12 11:31:40 node2 pengine: [3735]: notice: short_print: Slaves: [ node2 ] Jan 12 11:31:40 node2 pengine: [3735]: notice: short_print: Stopped: [ drbd_hadoop:1 ] Jan 12 11:31:40 node2 pengine: [3735]: info: native_color: Resource drbd_hadoop:1 cannot run anywhere Jan 12 11:31:40 node2 pengine: [3735]: info: master_color: ms_drbd: Promoted 0 instances of a possible 1 to master Jan 12 11:31:40 node2 pengine: [3735]: notice: RecurringOp: Start recurring monitor (20s) for drbd_hadoop:0 on node2 Jan 12 11:31:40 node2 pengine: [3735]: notice: RecurringOp: Start recurring monitor (20s) for drbd_hadoop:0 on node2 Jan 12 11:31:40 node2 pengine: [3735]: notice: LogActions: Leave resource drbd_hadoop:0 (Slave node2) Jan 12 11:31:40 node2 pengine: [3735]: notice: LogActions: Leave resource drbd_hadoop:1 (Stopped) -- ******************************** $B%9%?!<%7%9%F%`%:3t<02q<R(B $BEl5~ET9A6hFn@D;3(B7-10-3 $BFn@D;3(BST$B%S%k(B5F $B<D5\!!H;?M(B TEL:03-5774-4086 FAX:03-3409-3135 E-Mail:hayato [at] starsystems ******************************** _______________________________________________ Linux-ha-japan mailing list Linux-ha-japan [at] lists http://lists.sourceforge.jp/mailman/listinfo/linux-ha-japan
|