<div class="gmail_quote">On Tue, May 25, 2010 at 3:39 PM, Dejan Muhamedagic <span dir="ltr"><<a href="mailto:dejanmm@fastmail.fm">dejanmm@fastmail.fm</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex;">
Hi,<br>
<div><div></div><div class="h5">[snip]<br>
> So I presume the problem could be caused by the fact that the second part is<br>
> a clone and not a resource? or a bug?<br>
> I can eventually send the whole config.<br>
<br>
</div></div>Looks like a bug to me. Clone or resource, constraints should be<br>
observed. Perhaps it's a duplicate of this one:<br>
<a href="http://developerbugs.linux-foundation.org/show_bug.cgi?id=2422" target="_blank">http://developerbugs.linux-foundation.org/show_bug.cgi?id=2422</a><br>
<div class="im"><br></div></blockquote><div><br></div><div>I don't know if it is the same bug...</div><div>In the sense that in your bug case the problem is related to:</div><div>- the stop operation not enforcing the order constraint </div>
<div>- the constraint is between a clone of a group and a clone of a resource</div><div><br></div><div>In my case the problem arises in:</div><div>- the start operation not enforcing the order constraint</div><div>- the constraint is between a group and a clone of a group</div>
<div>Verified also when</div><div>- the constraint is between a resource and a clone of a group</div><div><br></div><div>Clone of a group is the second part of the two. Not tested in reverse.</div><div><br></div><div>So probably a common root cause for the problems, if exists, could be related with the clone part...</div>
<div>In the meantime, in my case, I put this workaround:</div><div>I set my nfsclient resource with the mount options "bg,intr",</div><div>the important part here being the bg one.</div><div>But I think in general also the intr option could be useful in case the cluster needs to do some operations (no soft option, so in my case hard should be the default, avoiding possible data corruption, correct?)</div>
<div><br></div><div>So now it is:</div><div><div>primitive nfsclient ocf:heartbeat:Filesystem \</div><div> params device="nfssrv:/nfsdata/web" directory="/usr/local/data" fstype="nfs" options="intr,bg" \</div>
<div> op monitor interval="30" timeout="40" depth="0" \</div><div> op start interval="0" timeout="60" \</div><div> op stop interval="0" timeout="60"</div>
</div><div><br></div><div>this way the start of the nfsclient succeeds (in terms of return codes ;-)</div><div>then the first monitor for nfsclient fails and then the consequent stop/start part of nfsclient succeeds, so that I can start successfully the resources...</div>
<div><br></div><div>See below the related lines that show the behavior.</div><div>At the end my cluster status, after I start corosync on one node (the other node being powered on but with corosync stopped) is now correctly:</div>
<div><br></div><div><div>root@node1 ~]# crm_mon -fr1</div><div>============</div><div>Last updated: Thu May 27 17:56:52 2010</div><div>Stack: openais</div><div>Current DC: node1. - partition WITHOUT quorum</div><div>Version: 1.0.8-9881a7350d6182bae9e8e557cf20a3cc5dac3ee7</div>
<div>2 Nodes configured, 2 expected votes</div><div>4 Resources configured.</div><div>============</div><div><br></div><div>Online: [ node1. ]</div><div>OFFLINE: [ node2. ]</div><div><br></div><div>Full list of resources:</div>
<div><br></div><div> Master/Slave Set: NfsData</div><div> Masters: [ node1. ]</div><div> Stopped: [ nfsdrbd:1 ]</div><div> Resource Group: nfs-group</div><div> lv_nfsdata_drbd (ocf::heartbeat:LVM): Started</div>
<div>node1.</div><div> NfsFS (ocf::heartbeat:Filesystem): Started</div><div>node1.</div><div> VIPlbtest (ocf::heartbeat:IPaddr2): Started</div><div>node1.</div><div> nfssrv (ocf::heartbeat:nfsserver): Started</div>
<div>node1.</div><div> Clone Set: cl-pinggw</div><div> Started: [ node1. ]</div><div> Stopped: [ pinggw:1 ]</div><div> Clone Set: apache_clone</div><div> Started: [ node1. ]</div><div> Stopped: [ apache_group:1 ]</div>
<div><br></div><div>Migration summary:</div><div>* Node node1.: pingd=200</div><div> nfsclient:0: migration-threshold=1000000 fail-count=1</div></div><div><br></div><div><div><div><div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Promote nfsdrbd:0 (Slave -> Master node1.)</div>
<div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource nfsdrbd:1 (Stopped)</div><div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource lv_nfsdata_drbd (Stopped)</div>
<div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource NfsFS (Stopped)</div><div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource VIPlbtest (Stopped)</div><div>
May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource nfssrv (Stopped)</div><div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource pinggw:0 (Started node1.)</div><div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource pinggw:1 (Stopped)</div>
<div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Start nfsclient:0 (node1.)</div><div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Start apachepoli:0 (node1.)</div><div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource nfsclient:1 (Stopped)</div>
<div>May 27 17:26:30 node1 pengine: [32373]: notice: LogActions: Leave resource apachepoli:1 (Stopped)</div><div>...</div><div>May 27 17:26:30 node1 lrmd: [32371]: info: rsc:nfsdrbd:0:14: notify</div><div>...</div><div>
May 27 17:26:30 node1 crmd: [32374]: info: do_lrm_rsc_op: Performing key=43:2:0:6b4ec352-3854-4caf-8882-8f060ba68420 op=nfsclient:0_start_0 )</div><div>May 27 17:26:30 node1 lrmd: [32371]: info: rsc:nfsclient:0:15: start</div>
<div>May 27 17:26:30 node1 Filesystem[32729]: INFO: Running start for viplbtest.:/nfsdata/web on /usr/local/data</div><div>May 27 17:26:30 node1 crmd: [32374]: info: process_lrm_event: LRM operation nfsdrbd:0_notify_0 (call=14, rc=0, cib-update=41, confirmed=true) ok</div>
<div>May 27 17:26:30 node1 crmd: [32374]: info: match_graph_event: Action nfsdrbd:0_pre_notify_promote_0 (85) confirmed on node1. (rc=0)</div><div>May 27 17:26:30 node1 crmd: [32374]: info: te_pseudo_action: Pseudo action 23 fired and confirmed</div>
<div>...</div><div>May 27 17:26:30 node1 kernel: block drbd0: role( Secondary -> Primary )</div><div>May 27 17:26:30 node1 lrmd: [32371]: info: RA output: (nfsdrbd:0:promote:stdout)</div><div>May 27 17:26:30 node1 crmd: [32374]: info: process_lrm_event: LRM operation nfsdrbd:0_promote_0 (call=16, rc=0, cib-update=42, confirmed=true) ok</div>
<div>May 27 17:26:30 node1 crmd: [32374]: info: match_graph_event: Action nfsdrbd:0_promote_0 (7) confirmed on node1. (rc=0)</div><div>...</div><div>May 27 17:26:43 node1 crmd: [32374]: info: process_lrm_event: LRM operation nfsclient:0_start_0 (call=15, rc=0, cib-update=45, confirmed=true) ok</div>
<div>May 27 17:26:43 node1 crmd: [32374]: info: match_graph_event: Action nfsclient:0_start_0 (43) confirmed on node1. (rc=0)</div><div><br></div><div>...</div><div>May 27 17:26:43 node1 pengine: [32373]: info: determine_online_status: Node node1. is online</div>
<div>May 27 17:26:43 node1 pengine: [32373]: notice: clone_print: Master/Slave Set: NfsData</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: short_print: Masters: [ node1. ]</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: short_print: Stopped: [ nfsdrbd:1 ]</div>
<div>May 27 17:26:43 node1 pengine: [32373]: notice: group_print: Resource Group: nfs-group</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: native_print: lv_nfsdata_drbd (ocf::heartbeat:LVM): Stopped</div>
<div>May 27 17:26:43 node1 pengine: [32373]: notice: native_print: NfsFS (ocf::heartbeat:Filesystem): Stopped</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: native_print: VIPlbtest (ocf::heartbeat:IPaddr2): Stopped</div>
<div>May 27 17:26:43 node1 pengine: [32373]: notice: native_print: nfssrv (ocf::heartbeat:nfsserver): Stopped</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: clone_print: Clone Set: cl-pinggw</div><div>
May 27 17:26:43 node1 pengine: [32373]: notice: short_print: Started: [ node1. ]</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: short_print: Stopped: [ pinggw:1 ]</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: clone_print: Clone Set: apache_clone</div>
<div>May 27 17:26:43 node1 pengine: [32373]: notice: group_print: Resource Group: apache_group:0</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: native_print: nfsclient:0 (ocf::heartbeat:Filesystem): Started node1.</div>
<div>May 27 17:26:43 node1 pengine: [32373]: notice: native_print: apachepoli:0 (ocf::poli:apache2): Stopped</div><div>May 27 17:26:43 node1 pengine: [32373]: notice: short_print: Stopped: [ apache_group:1 ]</div>
<div>...</div><div>May 27 17:26:43 node1 pengine: [32373]: info: master_color: Promoting nfsdrbd:0 (Master node1.)</div><div>May 27 17:26:43 node1 pengine: [32373]: info: master_color: NfsData: Promoted 1 instances of a possible 1 to master</div>
<div>...</div><div>May 27 17:26:43 node1 lrmd: [32371]: info: rsc:lv_nfsdata_drbd:18: start</div><div>May 27 17:26:43 node1 crmd: [32374]: info: te_rsc_command: Initiating action 51: monitor nfsclient:0_monitor_30000 on node1. (local)</div>
<div>May 27 17:26:43 node1 crmd: [32374]: info: do_lrm_rsc_op: Performing key=51:3:0:6b4ec352-3854-4caf-8882-8f060ba68420 op=nfsclient:0_monitor_30000 )</div><div>May 27 17:26:43 node1 lrmd: [32371]: info: rsc:nfsclient:0:19: monitor</div>
<div>May 27 17:26:43 node1 LVM[411]: INFO: Activating volume group vg_nfsdata_drbd</div><div>May 27 17:26:43 node1 crmd: [32374]: info: process_lrm_event: LRM operation nfsclient:0_monitor_30000 (call=19, rc=7, cib-update=47, confirmed=false) not running</div>
<div>May 27 17:26:43 node1 crmd: [32374]: WARN: status_from_rc: Action 51 (nfsclient:0_monitor_30000) on node1. failed (target: 0 vs. rc: 7): Error</div><div>May 27 17:26:43 node1 crmd: [32374]: WARN: update_failcount: Updating failcount for nfsclient:0 on node1. after failed monitor: rc=7 (update=value++, time=1274974003)</div>
<div>...</div><div>May 27 17:26:43 node1 crmd: [32374]: info: match_graph_event: Action nfsclient:0_monitor_30000 (51) confirmed on node1. (rc=4)</div><div>May 27 17:26:43 node1 attrd: [32372]: info: find_hash_entry: Creating hash entry for fail-count-nfsclient:0</div>
<div>May 27 17:26:43 node1 attrd: [32372]: info: attrd_local_callback: Expanded fail-count-nfsclient:0=value++ to 1</div><div>May 27 17:26:43 node1 attrd: [32372]: info: attrd_trigger_update: Sending flush op to all hosts for: fail-count-nfsclient:0 (1)</div>
<div>May 27 17:26:43 node1 attrd: [32372]: info: attrd_perform_update: Sent update 17: fail-count-nfsclient:0=1</div><div>...</div><div>May 27 17:26:43 node1 LVM[411]: INFO: Reading all physical volumes. This may take a while... Found volume group "VolGroup00" using metadata type lvm2 Found volume group "vg_nfsdata_drbd" using metadata type lvm2</div>
<div>May 27 17:26:44 node1 LVM[411]: INFO: 1 logical volume(s) in volume group "vg_nfsdata_drbd" now active</div><div>May 27 17:26:44 node1 crmd: [32374]: info: process_lrm_event: LRM operation lv_nfsdata_drbd_start_0 (call=18, rc=0, cib-update=48, confirmed=true) ok</div>
<div>May 27 17:26:44 node1 crmd: [32374]: info: match_graph_event: Action lv_nfsdata_drbd_start_0 (33) confirmed on node1. (rc=0)</div><div>...</div><div>May 27 17:26:44 node1 pengine: [32373]: info: determine_online_status: Node node1. is online</div>
<div>May 27 17:26:44 node1 pengine: [32373]: WARN: unpack_rsc_op: Processing failed op nfsclient:0_monitor_30000 on node1.: not running (7)</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: clone_print: Master/Slave Set: NfsData</div>
<div>May 27 17:26:44 node1 pengine: [32373]: notice: short_print: Masters: [ node1. ]</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: short_print: Stopped: [ nfsdrbd:1 ]</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: group_print: Resource Group: nfs-group</div>
<div>May 27 17:26:44 node1 pengine: [32373]: notice: native_print: lv_nfsdata_drbd (ocf::heartbeat:LVM): Started node1.</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: native_print: NfsFS (ocf::heartbeat:Filesystem): Stopped</div>
<div>May 27 17:26:44 node1 pengine: [32373]: notice: native_print: VIPlbtest (ocf::heartbeat:IPaddr2): Stopped</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: native_print: nfssrv (ocf::heartbeat:nfsserver): Stopped</div>
<div>May 27 17:26:44 node1 pengine: [32373]: notice: clone_print: Clone Set: cl-pinggw</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: short_print: Started: [ node1. ]</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: short_print: Stopped: [ pinggw:1 ]</div>
<div>May 27 17:26:44 node1 pengine: [32373]: notice: clone_print: Clone Set: apache_clone</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: group_print: Resource Group: apache_group:0</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: native_print: nfsclient:0 (ocf::heartbeat:Filesystem): Started node1. FAILED</div>
<div>May 27 17:26:44 node1 pengine: [32373]: notice: native_print: apachepoli:0 (ocf::poli:apache2): Stopped</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: short_print: Stopped: [ apache_group:1 ]</div>
<div>May 27 17:26:44 node1 pengine: [32373]: info: get_failcount: apache_clone has failed 1 times on node1.</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: common_apply_stickiness: apache_clone can fail 999999 more times on node1. before being forced off</div>
<div>...</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: LogActions: Recover resource nfsclient:0 (Started node1.)</div><div>May 27 17:26:44 node1 pengine: [32373]: notice: LogActions: Start apachepoli:0 (node1.)</div>
<div>...</div><div>May 27 17:26:44 node1 crmd: [32374]: info: te_rsc_command: Initiating action 38: start NfsFS_start_0 on node1. (local)</div><div>May 27 17:26:44 node1 crmd: [32374]: info: do_lrm_rsc_op: Performing key=38:4:0:6b4ec352-3854-4caf-8882-8f060ba68420 op=NfsFS_start_0 )</div>
<div>May 27 17:26:44 node1 lrmd: [32371]: info: rsc:NfsFS:21: start</div><div>...</div><div>May 27 17:26:44 node1 crmd: [32374]: info: te_rsc_command: Initiating action 3: stop nfsclient:0_stop_0 on node1. (local)</div><div>
...</div><div>May 27 17:26:44 node1 crmd: [32374]: info: do_lrm_rsc_op: Performing key=3:4:0:6b4ec352-3854-4caf-8882-8f060ba68420 op=nfsclient:0_stop_0 )</div><div>May 27 17:26:44 node1 lrmd: [32371]: info: rsc:nfsclient:0:22: stop</div>
<div>...</div><div>May 27 17:26:44 node1 Filesystem[493]: INFO: Running start for /dev/vg_nfsdata_drbd/lv_nfsdata_drbd on /nfsdata</div><div>May 27 17:26:44 node1 Filesystem[502]: INFO: Running stop for viplbtest.:/nfsdata/web on /usr/local/data</div>
<div>May 27 17:26:44 node1 crmd: [32374]: info: process_lrm_event: LRM operation nfsclient:0_stop_0 (call=22, rc=0, cib-update=50, confirmed=true) ok</div><div>May 27 17:26:44 node1 crmd: [32374]: info: match_graph_event: Action nfsclient:0_stop_0 (3) confirmed on node1. (rc=0)</div>
<div>...</div><div>May 27 17:26:44 node1 kernel: kjournald starting. Commit interval 5 seconds</div></div></div></div><div><div>May 27 17:26:44 node1 kernel: EXT3-fs warning: maximal mount count reached, running e2fsck is recommended</div>
<div>May 27 17:26:44 node1 kernel: EXT3 FS on dm-0, internal journal</div><div>May 27 17:26:44 node1 kernel: EXT3-fs: mounted filesystem with ordered data mode.</div><div>May 27 17:26:44 node1 crmd: [32374]: info: process_lrm_event: LRM operation NfsFS_start_0 (call=21, rc=0, cib-update=51, confirmed=true) ok</div>
<div>...</div><div>May 27 17:26:44 node1 crmd: [32374]: info: te_rsc_command: Initiating action 39: start VIPlbtest_start_0 on node1. (local)</div><div>May 27 17:26:44 node1 crmd: [32374]: info: do_lrm_rsc_op: Performing key=39:4:0:6b4ec352-3854-4caf-8882-8f060ba68420 op=VIPlbtest_start_0 )</div>
<div>May 27 17:26:44 node1 lrmd: [32371]: info: rsc:VIPlbtest:23: start</div><div>...</div><div>May 27 17:26:44 node1 crmd: [32374]: info: process_lrm_event: LRM operation VIPlbtest_start_0 (call=23, rc=0, cib-update=53, confirmed=true) ok</div>
<div>...</div><div>May 27 17:26:44 node1 crmd: [32374]: info: te_rsc_command: Initiating action 41: start nfssrv_start_0 on node1. (local)</div><div>May 27 17:26:44 node1 crmd: [32374]: info: do_lrm_rsc_op: Performing key=41:4:0:6b4ec352-3854-4caf-8882-8f060ba68420 op=nfssrv_start_0 )</div>
<div>May 27 17:26:44 node1 lrmd: [32371]: info: rsc:nfssrv:25: start</div><div>...</div><div>May 27 17:26:44 node1 nfsserver[661]: INFO: Starting NFS server ...</div><div>May 27 17:26:44 node1 kernel: NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory</div>
<div>May 27 17:26:44 node1 kernel: NFSD: starting 90-second grace period</div><div>May 27 17:26:44 node1 lrmd: [32371]: info: RA output: (nfssrv:start:stdout) rpc.statd version 1.0.9</div><div>May 27 17:26:44 node1 nfsserver[661]: INFO: NFS server started</div>
<div>May 27 17:26:44 node1 crmd: [32374]: info: process_lrm_event: LRM operation nfssrv_start_0 (call=25, rc=0, cib-update=55, confirmed=true) ok</div><div>...</div><div>May 27 17:26:44 node1 crmd: [32374]: info: te_rsc_command: Initiating action 52: start nfsclient:0_start_0 on node1. (local)</div>
<div>May 27 17:26:44 node1 crmd: [32374]: info: do_lrm_rsc_op: Performing key=52:4:0:6b4ec352-3854-4caf-8882-8f060ba68420 op=nfsclient:0_start_0 )</div><div>May 27 17:26:44 node1 lrmd: [32371]: info: rsc:nfsclient:0:26: start</div>
<div>May 27 17:26:45 node1 Filesystem[771]: INFO: Running start for viplbtest.:/nfsdata/web on /usr/local/data</div><div>May 27 17:26:46 node1 mountd[746]: authenticated mount request from <a href="http://10.4.4.140:921">10.4.4.140:921</a> for /nfsdata/web (/nfsdata/web)</div>
<div>May 27 17:26:46 node1 mountd[746]: authenticated mount request from <a href="http://10.4.4.140:999">10.4.4.140:999</a> for /nfsdata/web (/nfsdata/web)</div><div>May 27 17:26:46 node1 crmd: [32374]: info: process_lrm_event: LRM operation nfsclient:0_start_0 (call=26, rc=0, cib-update=56, confirmed=true) ok</div>
<div>May 27 17:26:46 node1 crmd: [32374]: info: match_graph_event: Action nfsclient:0_start_0 (52) confirmed on node1. (rc=0)</div></div><div><br></div></div>