Am Dienstag, 26. Mai 2009 10:26:46 schrieb Andrew Beekhof:
> On Tue, May 26, 2009 at 10:19 AM, Michael Schwartzkopff
>
> <[email protected]> wrote:
> > Am Dienstag, 26. Mai 2009 09:42:53 schrieb Andrew Beekhof:
>
> [snip]
>
> >> The cluster can't react to the current event until all the actions it
> >> took in order to react to the previous event have finished.
> >> This is what is happening here and its the resDRBD:1_monitor_20000
> >> action that we're blocking on.
> >>
> >> May 26 08:18:14 mom2 crmd: [2808]: info: te_rsc_command: Initiating
> >> action 13: monitor resDRBD:1_monitor_20000 on mom2 (local)
> >>
> >> May 26 08:19:14 mom2 crmd: [2808]: info: process_lrm_event: LRM
> >> operation resDRBD:1_monitor_20000 (call=65, rc=0, cib-update=173,
> >> confirmed=false) complete ok
> >
> > OK. Your answer leads me to the next question: What causes the monitor
> > operation to take 1 minute?
>
> No idea, but the answer will be in the drbd RA

Hi,

The problem is in the CRM, not in the RA. I configured a pingd clone and this  
resource behaves identically. One minute timeout when one node is set to 
standby. See log attached. I file a bugreport.





-- 
Dr. Michael Schwartzkopff
MultiNET Services GmbH
Addresse: Bretonischer Ring 7; 85630 Grasbrunn; Germany
Tel: +49 - 89 - 45 69 11 0
Fax: +49 - 89 - 45 69 11 21
mob: +49 - 174 - 343 28 75

mail: [email protected]
web: www.multinet.de

Sitz der Gesellschaft: 85630 Grasbrunn
Registergericht: Amtsgericht München HRB 114375
Geschäftsführer: Günter Jurgeneit, Hubert Martens

---

PGP Fingerprint: F919 3919 FF12 ED5A 2801 DEA6 AA77 57A4 EDD8 979B
Skype: misch42
May 26 12:01:47 mom2 mgmtd: [2622]: info: CIB query: cib
May 26 12:01:55 mom2 crmd: [2621]: info: abort_transition_graph: need_abort:59 
- Triggered transition abort (complete=0) : Non-status change
May 26 12:01:55 mom2 crmd: [2621]: info: update_abort_priority: Abort priority 
upgraded from 0 to 1000000
May 26 12:01:55 mom2 crmd: [2621]: info: update_abort_priority: Abort action 
done superceeded by restart
May 26 12:01:55 mom2 crmd: [2621]: info: need_abort: Aborting on change to 
admin_epoch
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: - <cib 
admin_epoch="0" epoch="50" num_updates="2" >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -   
<configuration >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -     
<nodes >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -       
<node id="a8254f3f-a97d-45d6-8da3-f72c4d2da1ba" >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -         
<instance_attributes id="nodes-a8254f3f-a97d-45d6-8da3-f72c4d2da1ba" >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -           
<nvpair value="false" id="standby-a8254f3f-a97d-45d6-8da3-f72c4d2da1ba" />
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -         
</instance_attributes>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -       
</node>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -     
</nodes>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: -   
</configuration>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: - </cib>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: + <cib 
admin_epoch="0" epoch="51" num_updates="1" >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +   
<configuration >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +     
<nodes >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +       
<node id="a8254f3f-a97d-45d6-8da3-f72c4d2da1ba" >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +         
<instance_attributes id="nodes-a8254f3f-a97d-45d6-8da3-f72c4d2da1ba" >
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +           
<nvpair value="true" id="standby-a8254f3f-a97d-45d6-8da3-f72c4d2da1ba" />
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +         
</instance_attributes>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +       
</node>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +     
</nodes>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: +   
</configuration>
May 26 12:01:55 mom2 cib: [2617]: info: log_data_element: cib:diff: + </cib>
May 26 12:01:55 mom2 cib: [2617]: info: cib_process_request: Operation 
complete: op cib_modify for section nodes (origin=local/mgmtd/127, 
version=0.51.1): ok (rc=0)
May 26 12:01:55 mom2 cib: [5702]: info: write_cib_contents: Archived previous 
version as /var/lib/heartbeat/crm/cib-49.raw
May 26 12:01:55 mom2 cib: [5702]: info: write_cib_contents: Wrote version 
0.51.0 of the CIB to disk (digest: 20b45869cb77e17c26da9d8e099f91cd)
May 26 12:01:55 mom2 cib: [5702]: info: retrieveCib: Reading cluster 
configuration from: /var/lib/heartbeat/crm/cib.ccoFTJ (digest: 
/var/lib/heartbeat/crm/cib.FZ6gif)
May 26 12:01:55 mom2 mgmtd: [2622]: info: CIB query: cib
May 26 12:02:47 mom2 crmd: [2621]: info: match_graph_event: Action 
resPingd:0_monitor_10000 (31) confirmed on mom1 (rc=0)
May 26 12:02:47 mom2 crmd: [2621]: info: run_graph: 
====================================================
May 26 12:02:47 mom2 crmd: [2621]: notice: run_graph: Transition 33 
(Complete=4, Pending=0, Fired=0, Skipped=0, Incomplete=0, 
Source=/var/lib/pengine/pe-warn-305.bz2): Complete
May 26 12:02:47 mom2 crmd: [2621]: info: te_graph_trigger: Transition 33 is now 
complete
May 26 12:02:47 mom2 crmd: [2621]: info: do_state_transition: State transition 
S_TRANSITION_ENGINE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_FSA_INTERNAL 
origin=notify_crmd ]
May 26 12:02:47 mom2 crmd: [2621]: info: do_state_transition: All 2 cluster 
nodes are eligible to run resources.
May 26 12:02:47 mom2 crmd: [2621]: info: do_pe_invoke: Query 126: Requesting 
the current CIB: S_POLICY_ENGINE
May 26 12:02:47 mom2 pengine: [2624]: notice: unpack_config: On loss of CCM 
Quorum: Ignore
May 26 12:02:47 mom2 pengine: [2624]: info: determine_online_status: Node mom2 
is online
May 26 12:02:47 mom2 pengine: [2624]: info: unpack_status: Node mom1 is in 
standby-mode
May 26 12:02:47 mom2 pengine: [2624]: info: determine_online_status: Node mom1 
is standby
May 26 12:02:47 mom2 pengine: [2624]: notice: clone_print: Master/Slave Set: 
msMyDRBD
May 26 12:02:47 mom2 pengine: [2624]: notice: print_list: #011Stopped: [ 
resMyDRBD:0 resMyDRBD:1 ]
May 26 12:02:47 mom2 pengine: [2624]: notice: clone_print: Clone Set: clonePingd
May 26 12:02:47 mom2 pengine: [2624]: notice: print_list: #011Started: [ mom1 
mom2 ]
May 26 12:02:47 mom2 pengine: [2624]: WARN: native_color: Resource resMyDRBD:0 
cannot run anywhere
May 26 12:02:47 mom2 pengine: [2624]: WARN: native_color: Resource resMyDRBD:1 
cannot run anywhere
May 26 12:02:47 mom2 pengine: [2624]: info: master_color: msMyDRBD: Promoted 0 
instances of a possible 1 to master
May 26 12:02:47 mom2 pengine: [2624]: WARN: native_color: Resource resPingd:0 
cannot run anywhere
May 26 12:02:47 mom2 pengine: [2624]: notice: LogActions: Leave resource 
resMyDRBD:0#011(Stopped)
May 26 12:02:47 mom2 pengine: [2624]: notice: LogActions: Leave resource 
resMyDRBD:1#011(Stopped)
May 26 12:02:47 mom2 pengine: [2624]: notice: LogActions: Stop resource 
resPingd:0#011(mom1)
May 26 12:02:47 mom2 pengine: [2624]: notice: LogActions: Leave resource 
resPingd:1#011(Started mom2)
May 26 12:02:47 mom2 crmd: [2621]: info: do_pe_invoke_callback: Invoking the 
PE: ref=pe_calc-dc-1243332167-147, seq=2, quorate=1
May 26 12:02:47 mom2 crmd: [2621]: info: do_state_transition: State transition 
S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE 
origin=handle_response ]
May 26 12:02:47 mom2 crmd: [2621]: info: unpack_graph: Unpacked transition 34: 
4 actions in 4 synapses
May 26 12:02:47 mom2 crmd: [2621]: info: do_te_invoke: Processing graph 34 
(ref=pe_calc-dc-1243332167-147) derived from /var/lib/pengine/pe-warn-306.bz2
May 26 12:02:47 mom2 crmd: [2621]: info: te_pseudo_action: Pseudo action 36 
fired and confirmed
May 26 12:02:47 mom2 crmd: [2621]: info: te_rsc_command: Initiating action 31: 
stop resPingd:0_stop_0 on mom1
May 26 12:02:47 mom2 pengine: [2624]: WARN: process_pe_message: Transition 34: 
WARNINGs found during PE processing. PEngine Input stored in: 
/var/lib/pengine/pe-warn-306.bz2
May 26 12:02:47 mom2 pengine: [2624]: info: process_pe_message: Configuration 
WARNINGs found during PE processing.  Please run "crm_verify -L" to identify 
issues.
May 26 12:02:47 mom2 mgmtd: [2622]: info: CIB query: cib
May 26 12:02:48 mom2 crmd: [2621]: info: match_graph_event: Action 
resPingd:0_stop_0 (31) confirmed on mom1 (rc=0)
May 26 12:02:48 mom2 crmd: [2621]: info: te_pseudo_action: Pseudo action 37 
fired and confirmed
May 26 12:02:48 mom2 crmd: [2621]: info: te_pseudo_action: Pseudo action 3 
fired and confirmed
May 26 12:02:48 mom2 crmd: [2621]: info: run_graph: 
====================================================
May 26 12:02:48 mom2 crmd: [2621]: notice: run_graph: Transition 34 
(Complete=4, Pending=0, Fired=0, Skipped=0, Incomplete=0, 
Source=/var/lib/pengine/pe-warn-306.bz2): Complete
May 26 12:02:48 mom2 crmd: [2621]: info: te_graph_trigger: Transition 34 is now 
complete
May 26 12:02:48 mom2 crmd: [2621]: info: notify_crmd: Transition 34 status: 
done - <null>
May 26 12:02:48 mom2 crmd: [2621]: info: do_state_transition: State transition 
S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL 
origin=notify_crmd ]
May 26 12:02:48 mom2 crmd: [2621]: info: do_state_transition: Starting PEngine 
Recheck Timer
May 26 12:02:49 mom2 mgmtd: [2622]: info: CIB query: cib
_______________________________________________
Linux-HA mailing list
[email protected]
http://lists.linux-ha.org/mailman/listinfo/linux-ha
See also: http://linux-ha.org/ReportingProblems

Reply via email to