Split brain due to keepalived apparently freezing in the vrrp master

We are having a recurrent issue in a group of three servers where one of 
the backup nodes grabs the virtual ip address because the master fails 
to send the vrrp advert with its priority for a few seconds and it also 
fails to run in time the local checks.

This results in a split brain scenario until the original master is able 
to broadcast its status again.

This is a recurring issue, happening several times a day, usually at 
times of higher than usual activity on the server, but not necessarily 
at periods of higher than usual network traffic.

All the servers are running Ubuntu 12.04 (we've seen a similar behavior 
in another group of servers running Ubuntu 14.04)
We are using keepalived version 1.2.13

This is the keepalived configuration that we are using:
---
global_defs {
   notification_email {
         xxx
   }
   notification_email_from xxx
   smtp_server xxx
   smtp_connect_timeout 30
}
vrrp_script mysql_died {
         script "/usr/local/bin/mysql_checker"
         interval 5
         fall 6
         rise 6
}
vrrp_script force_failover_reader {
         script "test \! -f /etc/keepalived/trigger.reader.failover"
         interval 5
}
vrrp_instance reader_vip_shard_0 {
         interface  bond0
         state BACKUP
         virtual_router_id 150
         priority 101
         advert_int 1
         authentication {
                auth_type PASS
                auth_pass xxxxx
         }
         virtual_ipaddress {
                172.16.255.55
         }
         track_script {
                 mysql_died weight -40
                 force_failover_reader weight -50
         }
         notify "/usr/local/bin/notify_mysql_failover.sh"
}
---

This is the initial keepalived status at the beginning of the incident:
db3: Master. Priority 101
db2: Backup. Priority 61
db1: Backup. Priority 101

What follows is all the data that we were able to capture during this 
incident.

tcpdump captured on db1 filtering all the adverts for 'vrid 150'. Notice 
the gap of vrrp adverts from db3 beginning at 13:09:29.
---
13:09:28.205765 IP db3 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:29.205840 IP db3 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:32.811435 IP db1 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:32.811530 IP db2 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 61, authtype simple, intvl 1s, length 20
13:09:32.811566 IP db1 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:32.811626 IP db2 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 61, authtype simple, intvl 1s, length 20
13:09:32.811646 IP db1 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:33.812474 IP db1 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:34.001709 IP db3 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:34.001751 IP db1 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:34.001842 IP db3 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
13:09:35.002100 IP db3 > vrrp.mcast.net: VRRPv2, Advertisement, vrid 
150, prio 101, authtype simple, intvl 1s, length 20
---

We keep a log of the results of the mysql_checker script used by keepalived.
These are the results on db3. There is an eight seconds gap beginning at 
13:09:27. The interval between checks should be five seconds.
---
2015-01-15 13:09:17 (66891): Check number 14605
2015-01-15 13:09:17 (66891): check_mysql_health will return 0
2015-01-15 13:09:22 (66973): Check number 14606
2015-01-15 13:09:22 (66973): check_mysql_health will return 0
2015-01-15 13:09:27 (67024): Check number 14607
2015-01-15 13:09:27 (67024): check_mysql_health will return 0
2015-01-15 13:09:35 (67318): Check number 14608
2015-01-15 13:09:35 (67318): check_mysql_health will return 0
2015-01-15 13:09:40 (67427): Check number 14609
2015-01-15 13:09:40 (67427): check_mysql_health will return 0
---

Keepalived entries in the syslog of db3 at the time of the incident:
---
Jan 15 13:09:34 db3 Keepalived_vrrp[48241]: 
VRRP_Instance(reader_vip_shard_0) Received lower prio advert, forcing 
new election
Jan 15 13:09:34 db3 Keepalived_vrrp[48241]: 
VRRP_Instance(reader_vip_shard_0) Received lower prio advert, forcing 
new election
---

Keepalived entries in the syslog of db1 at the time of the incident:
---
Jan 15 13:09:32 db1 Keepalived_vrrp[39988]: 
VRRP_Instance(reader_vip_shard_0) Transition to MASTER STATE
Jan 15 13:09:32 db1 Keepalived_vrrp[39988]: 
VRRP_Instance(reader_vip_shard_0) Received lower prio advert, forcing 
new election
Jan 15 13:09:32 db1 Keepalived_vrrp[39988]: 
VRRP_Instance(reader_vip_shard_0) Received lower prio advert, forcing 
new election
Jan 15 13:09:33 db1 Keepalived_vrrp[39988]: 
VRRP_Instance(reader_vip_shard_0) Entering MASTER STATE
Jan 15 13:09:33 db1 Keepalived_vrrp[39988]: Opening script file 
/usr/local/bin/notify_mysql_failover.sh
Jan 15 13:09:34 db1 Keepalived_vrrp[39988]: 
VRRP_Instance(reader_vip_shard_0) Received higher prio advert
Jan 15 13:09:34 db1 Keepalived_vrrp[39988]: 
VRRP_Instance(reader_vip_shard_0) Entering BACKUP STATE
Jan 15 13:09:34 db1 Keepalived_vrrp[39988]: Opening script file 
/usr/local/bin/notify_mysql_failover.sh
---

---

Sergio Roysen
Operations - Shopify



------------------------------------------------------------------------------
New Year. New Location. New Benefits. New Data Center in Ashburn, VA.
GigeNET is offering a free month of service with a new server in Ashburn.
Choose from 2 high performing configs, both with 100TB of bandwidth.
Higher redundancy.Lower latency.Increased capacity.Completely compliant.
http://p.sf.net/sfu/gigenet