Jake,
Attached is the log from the same period for node2. If I am reading this correctly, it looks like there was a 7 second difference between when node1 set its score to 1000 and when node2 set its score to 1000? Aug 22 10:40:38 node1 attrd_updater: [1860]: info: Invoked: attrd_updater -n p_ping -v 1000 -d 5s Aug 22 10:40:43 node1 attrd: [4402]: notice: attrd_trigger_update: Sending flush op to all hosts for: p_ping (1000) Aug 22 10:40:44 node1 attrd: [4402]: notice: attrd_perform_update: Sent update 265: p_ping=1000 Aug 22 10:40:45 node2 attrd_updater: [27245]: info: Invoked: attrd_updater -n p_ping -v 1000 -d 5s Aug 22 10:40:50 node2 attrd: [4069]: notice: attrd_trigger_update: Sending flush op to all hosts for: p_ping (1000) Aug 22 10:40:50 node2 attrd: [4069]: notice: attrd_perform_update: Sent update 122: p_ping=1000 I had changed the attempts value to 8 (from the default 2) to address this same issue - to avoid resource migration based on brief connectivity problems with these IPs - however if we can get dampen configured correctly I'll set it back to the default. Thanks, Andrew ----- Original Message ----- From: "Jake Smith" <jsm...@argotec.com> To: "The Pacemaker cluster resource manager" <pacemaker@oss.clusterlabs.org> Sent: Monday, August 27, 2012 9:39:30 AM Subject: Re: [Pacemaker] Loss of ocf:pacemaker:ping target forces resources to restart? ----- Original Message ----- > From: "Andrew Martin" <amar...@xes-inc.com> > To: "The Pacemaker cluster resource manager" <pacemaker@oss.clusterlabs.org> > Sent: Thursday, August 23, 2012 7:36:26 PM > Subject: Re: [Pacemaker] Loss of ocf:pacemaker:ping target forces resources > to restart? > > Hi Florian, > > > Thanks for the suggestion. I gave it a try, but even with a dampen > value greater than 2* the monitoring interval the same behavior > occurred (pacemaker restarted the resources on the same node). Here > are my current ocf:pacemaker:ping settings: > > primitive p_ping ocf:pacemaker:ping \ > params name="p_ping" host_list="192.168.0.128 192.168.0.129" > dampen="25s" multiplier="1000" attempts="8" debug="true" \ > op start interval="0" timeout="60" \ > op monitor interval="10s" timeout="60" > > > Any other ideas on what is causing this behavior? My understanding is > the above config tells the cluster to attempt 8 pings to each of the > IPs, and will assume that an IP is down if none of the 8 come back. > Thus, an IP would have to be down for more than 8 seconds to be > considered down. The dampen parameter tells the cluster to wait > before making any decision, so that if the IP comes back online > within the dampen period then no action is taken. Is this correct? > > I'm no expert on this either but I believe the dampen isn't long enough - I think what you say above is correct but not only does the IP need to come back online but the cluster must attempt to ping it successfully also. I would suggest trying dampen with greater than 3*monitor value. I don't think it's a problem but why change the attempts from the default 2 to 8? > Thanks, > > > Andrew > > > ----- Original Message ----- > > From: "Florian Crouzat" <gen...@floriancrouzat.net> > To: pacemaker@oss.clusterlabs.org > Sent: Thursday, August 23, 2012 3:57:02 AM > Subject: Re: [Pacemaker] Loss of ocf:pacemaker:ping target forces > resources to restart? > > Le 22/08/2012 18:23, Andrew Martin a écrit : > > Hello, > > > > > > I have a 3 node Pacemaker + Heartbeat cluster (two real nodes and 1 > > quorum node that cannot run resources) running on Ubuntu 12.04 > > Server amd64. This cluster has a DRBD resource that it mounts and > > then runs a KVM virtual machine from. I have configured the > > cluster to use ocf:pacemaker:ping with two other devices on the > > network (192.168.0.128, 192.168.0.129), and set constraints to > > move the resources to the most well-connected node (whichever node > > can see more of these two devices): > > > > primitive p_ping ocf:pacemaker:ping \ > > params name="p_ping" host_list="192.168.0.128 192.168.0.129" > > multiplier="1000" attempts="8" debug="true" \ > > op start interval="0" timeout="60" \ > > op monitor interval="10s" timeout="60" > > ... > > > > clone cl_ping p_ping \ > > meta interleave="true" > > > > ... > > location loc_run_on_most_connected g_vm \ > > rule $id="loc_run_on_most_connected-rule" p_ping: defined p_ping > > > > > > Today, 192.168.0.128's network cable was unplugged for a few > > seconds and then plugged back in. During this time, pacemaker > > recognized that it could not ping 192.168.0.128 and restarted all > > of the resources, but left them on the same node. My understanding > > was that since neither node could ping 192.168.0.128 during this > > period, pacemaker would do nothing with the resources (leave them > > running). It would only migrate or restart the resources if for > > example node2 could ping 192.168.0.128 but node1 could not (move > > the resources to where things are better-connected). Is this > > understanding incorrect? If so, is there a way I can change my > > configuration so that it will only restart/migrate resources if > > one node is found to be better connected? > > > > Can you tell me why these resources were restarted? I have attached > > the syslog as well as my full CIB configuration. > > As was said already the log shows node1 changed it's value for pingd to 1000, waited the 5 seconds of dampening and then started actions to move the resources. In the midst of stopping everything ping ran again successfully and the value increase back to 2000. This caused the policy engine to recalculate scores for all resources (before they had the chance to start on node2). I'm no scoring expert but I know there is additional value given to keep resources that are collocated together with their partners that are already running and resource stickiness to not move. So in this situation the score to stay/run on node1 once pingd was back at 2000 was greater that the score to move so things that were stopped or stopping restarted on node1. So increasing the dampen value should help/fix. Unfortunately you didn't include the log from node2 so we can't correlate what node2's pingd values are at the same times as node1. I believe if you look at the pingd values and times that movement is started between the nodes you will be able to make a better guess at how high a dampen value would make sure the nodes had the same pingd value *before* the dampen time ran out and that should prevent movement. HTH Jake > > Thanks, > > > > Andrew Martin > > > > This is an interesting question and I'm also interested in answers. > > I had the same observations, and there is also the case where the > monitor() aren't synced across all nodes so, "Node 1 issue a > monitor() > on the ping resource and finds ping-node dead, node2 hasn't pinged > yet, > so node1 moves things to node2 but node2 now issue a monitor() and > also > finds ping-node dead." > > The only solution I found was to adjust the dampen parameter to at > least > 2*monitor().interval so that I can be *sure* that all nodes have > issued > a monitor() and they all decreased they scores so that when a > decision > occurs, nothings move. > > It's been a long time I haven't tested, my cluster is very very > stable, > I guess I should retry to validate it's still a working trick. > > ==== > > dampen (integer, [5s]): Dampening interval > The time to wait (dampening) further changes occur > > Eg: > > primitive ping-nq-sw-swsec ocf:pacemaker:ping \ > params host_list="192.168.10.1 192.168.2.11 192.168.2.12" > dampen="35s" attempts="2" timeout="2" multiplier="100" \ > op monitor interval="15s" > > > > > -- > Cheers, > Florian Crouzat > > _______________________________________________ > Pacemaker mailing list: Pacemaker@oss.clusterlabs.org > http://oss.clusterlabs.org/mailman/listinfo/pacemaker > > Project Home: http://www.clusterlabs.org > Getting started: > http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf > Bugs: http://bugs.clusterlabs.org > > _______________________________________________ > Pacemaker mailing list: Pacemaker@oss.clusterlabs.org > http://oss.clusterlabs.org/mailman/listinfo/pacemaker > > Project Home: http://www.clusterlabs.org > Getting started: > http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf > Bugs: http://bugs.clusterlabs.org > > _______________________________________________ Pacemaker mailing list: Pacemaker@oss.clusterlabs.org http://oss.clusterlabs.org/mailman/listinfo/pacemaker Project Home: http://www.clusterlabs.org Getting started: http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf Bugs: http://bugs.clusterlabs.org
Aug 22 10:40:17 node2 attrd_updater: [27057]: info: Invoked: attrd_updater -n p_ping -v 2000 -d 5s Aug 22 10:40:38 node2 ping[27062]: [27167]: WARNING: 192.168.0.128 is inactive: PING 192.168.0.128 (192.168.0.128) 56(84) bytes of data.#012#012--- 192.168.0.128 ping statistics ---#0128 packets transmitted, 0 received, 100% packet loss, time 7054ms Aug 22 10:40:44 node2 lrmd: [4067]: info: cancel_op: operation monitor[36] on p_drbd_mount2:1 for client 4070, its parameters: drbd_resource=[crm] CRM_meta_role=[Slave] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_start_resource=[p_drbd_mount2:1 ] CRM_meta_notify_inactive_resource=[p_drbd_mount2:1 ] CRM_meta_notify_master_uname=[node1 ] CRM_meta_timeout=[30000] CRM_meta_name=[monitor] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_promote_uname=[ ] crm_feature_set=[3.0.5] CRM_meta_notify=[true] CRM_meta_notify_start_uname=[node2 ] CRM_meta_clo cancelled Aug 22 10:40:44 node2 crmd: [4070]: info: send_direct_ack: ACK'ing resource op p_drbd_mount2:1_monitor_20000 from 12:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5: lrm_invoke-lrmd-1345650044-33 Aug 22 10:40:44 node2 lrmd: [4067]: info: cancel_op: operation monitor[37] on p_drbd_mount1:1 for client 4070, its parameters: drbd_resource=[tools] CRM_meta_role=[Slave] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_start_resource=[p_drbd_mount1:1 ] CRM_meta_notify_inactive_resource=[p_drbd_mount1:1 ] CRM_meta_notify_master_uname=[node1 ] CRM_meta_timeout=[30000] CRM_meta_name=[monitor] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_promote_uname=[ ] crm_feature_set=[3.0.5] CRM_meta_notify=[true] CRM_meta_notify_start_uname=[node2 ] CRM_ cancelled Aug 22 10:40:44 node2 crmd: [4070]: info: send_direct_ack: ACK'ing resource op p_drbd_mount1:1_monitor_20000 from 8:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5: lrm_invoke-lrmd-1345650044-34 Aug 22 10:40:44 node2 lrmd: [4067]: info: cancel_op: operation monitor[38] on p_drbd_vmstore:1 for client 4070, its parameters: drbd_resource=[vmstore] CRM_meta_role=[Slave] CRM_meta_notify_stop_resource=[ ] CRM_meta_notify_start_resource=[p_drbd_vmstore:1 ] CRM_meta_notify_inactive_resource=[p_drbd_vmstore:1 ] CRM_meta_notify_master_uname=[node1 ] CRM_meta_timeout=[30000] CRM_meta_name=[monitor] CRM_meta_notify_demote_resource=[ ] CRM_meta_notify_promote_uname=[ ] crm_feature_set=[3.0.5] CRM_meta_notify=[true] CRM_meta_notify_start_uname=[node2 cancelled Aug 22 10:40:44 node2 crmd: [4070]: info: send_direct_ack: ACK'ing resource op p_drbd_vmstore:1_monitor_20000 from 9:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5: lrm_invoke-lrmd-1345650044-35 Aug 22 10:40:44 node2 crmd: [4070]: info: do_lrm_rsc_op: Performing key=170:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5 op=p_drbd_mount2:1_notify_0 ) Aug 22 10:40:44 node2 lrmd: [4067]: info: rsc:p_drbd_mount2:1 notify[40] (pid 27174) Aug 22 10:40:44 node2 crmd: [4070]: info: do_lrm_rsc_op: Performing key=186:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5 op=p_drbd_mount1:1_notify_0 ) Aug 22 10:40:44 node2 lrmd: [4067]: info: rsc:p_drbd_mount1:1 notify[41] (pid 27175) Aug 22 10:40:44 node2 crmd: [4070]: info: do_lrm_rsc_op: Performing key=202:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5 op=p_drbd_vmstore:1_notify_0 ) Aug 22 10:40:44 node2 lrmd: [4067]: info: rsc:p_drbd_vmstore:1 notify[42] (pid 27176) Aug 22 10:40:44 node2 crmd: [4070]: info: process_lrm_event: LRM operation p_drbd_mount2:1_monitor_20000 (call=36, status=1, cib-update=0, confirmed=true) Cancelled Aug 22 10:40:44 node2 crmd: [4070]: info: process_lrm_event: LRM operation p_drbd_mount1:1_monitor_20000 (call=37, status=1, cib-update=0, confirmed=true) Cancelled Aug 22 10:40:44 node2 crmd: [4070]: info: process_lrm_event: LRM operation p_drbd_vmstore:1_monitor_20000 (call=38, status=1, cib-update=0, confirmed=true) Cancelled Aug 22 10:40:44 node2 lrmd: [4067]: info: operation notify[40] on p_drbd_mount2:1 for client 4070: pid 27174 exited with return code 0 Aug 22 10:40:44 node2 lrmd: [4067]: info: operation notify[41] on p_drbd_mount1:1 for client 4070: pid 27175 exited with return code 0 Aug 22 10:40:44 node2 crmd: [4070]: info: send_direct_ack: ACK'ing resource op p_drbd_mount2:1_notify_0 from 170:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5: lrm_invoke-lrmd-1345650044-36 Aug 22 10:40:44 node2 crmd: [4070]: info: process_lrm_event: LRM operation p_drbd_mount2:1_notify_0 (call=40, rc=0, cib-update=0, confirmed=true) ok Aug 22 10:40:44 node2 lrmd: [4067]: info: operation notify[42] on p_drbd_vmstore:1 for client 4070: pid 27176 exited with return code 0 Aug 22 10:40:44 node2 crmd: [4070]: info: send_direct_ack: ACK'ing resource op p_drbd_mount1:1_notify_0 from 186:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5: lrm_invoke-lrmd-1345650044-37 Aug 22 10:40:44 node2 crmd: [4070]: info: process_lrm_event: LRM operation p_drbd_mount1:1_notify_0 (call=41, rc=0, cib-update=0, confirmed=true) ok Aug 22 10:40:44 node2 crmd: [4070]: info: send_direct_ack: ACK'ing resource op p_drbd_vmstore:1_notify_0 from 202:760:0:bc91a070-5215-4409-9d67-6ae8c99caeb5: lrm_invoke-lrmd-1345650044-38 Aug 22 10:40:44 node2 crmd: [4070]: info: process_lrm_event: LRM operation p_drbd_vmstore:1_notify_0 (call=42, rc=0, cib-update=0, confirmed=true) ok Aug 22 10:40:45 node2 attrd_updater: [27245]: info: Invoked: attrd_updater -n p_ping -v 1000 -d 5s Aug 22 10:40:50 node2 attrd: [4069]: notice: attrd_trigger_update: Sending flush op to all hosts for: p_ping (1000) Aug 22 10:40:50 node2 attrd: [4069]: notice: attrd_perform_update: Sent update 122: p_ping=1000 Aug 22 10:41:09 node2 attrd_updater: [27323]: info: Invoked: attrd_updater -n p_ping -v 2000 -d 5s Aug 22 10:41:14 node2 attrd: [4069]: notice: attrd_trigger_update: Sending flush op to all hosts for: p_ping (2000) Aug 22 10:41:14 node2 attrd: [4069]: notice: attrd_perform_update: Sent update 126: p_ping=2000 Aug 22 10:41:33 node2 attrd_updater: [27353]: info: Invoked: attrd_updater -n p_ping -v 2000 -d 5s Aug 22 10:41:57 node2 attrd_updater: [27387]: info: Invoked: attrd_updater -n p_ping -v 2000 -d 5s Aug 22 10:42:21 node2 attrd_updater: [27465]: info: Invoked: attrd_updater -n p_ping -v 2000 -d 5s Aug 22 10:42:45 node2 attrd_updater: [27499]: info: Invoked: attrd_updater -n p_ping -v 2000 -d 5s Aug 22 10:43:09 node2 attrd_updater: [27577]: info: Invoked: attrd_updater -n p_ping -v 2000 -d 5s Aug 22 10:43:33 node2 attrd_updater: [27607]: info: Invoked: attrd_updater -n p_ping -v 2000 -d 5s
_______________________________________________ Pacemaker mailing list: Pacemaker@oss.clusterlabs.org http://oss.clusterlabs.org/mailman/listinfo/pacemaker Project Home: http://www.clusterlabs.org Getting started: http://www.clusterlabs.org/doc/Cluster_from_Scratch.pdf Bugs: http://bugs.clusterlabs.org
