Re: VRRP packets with duplicate AH sequence number

Quentin Armitage <[email protected]> Wed, 03 May 2017 00:28:33 +0100
Newsgroups gmane.linux.keepalived.devel
Organization The Armitage family
Message-ID <[email protected]>
On Tue, 2017-04-25 at 17:39 +0300, Aleksey wrote:

> On 2017-03-24 16:30, Aleksey wrote:
> > On 2017-03-24 14:18, Quentin Armitage wrote:
> >> On Fri, 2017-03-24 at 12:49 +0200, Aleksey wrote:
> >> 
> >> Hi guys!
> >> 
> >> I have strange behavior of my keepalived running only as VRRP daemon.
> >> Sometimes it sends advertisements with the same sequence number and
> >> then
> >> errors on log appear:
> >> 
> >> 11:03:44.993382 IP 10.1.64.156 > 224.0.0.18:
> >> AH(spi=0x0a01409c,seq=0x10f9e47): VRRPv2, Advertisement, vrid 7, prio
> >> 200, authtype ah, intvl 1s, length 20
> >> 11:03:44.993393 IP 10.1.64.156 > 224.0.0.18:
> >> AH(spi=0x0a01409c,seq=0x10f9e47): VRRPv2, Advertisement, vrid 7, prio
> >> 200, authtype ah, intvl 1s, length 20
> >> 11:03:44.993414 IP 10.1.64.156 > 224.0.0.18:
> >> AH(spi=0x0a01409c,seq=0x10f9e47): VRRPv2, Advertisement, vrid 7, prio
> >> 200, authtype ah, intvl 1s, length 20
> >> 11:03:44.993422 IP 10.1.64.156 > 224.0.0.18:
> >> AH(spi=0x0a01409c,seq=0x10f9e47): VRRPv2, Advertisement, vrid 7, prio
> >> 200, authtype ah, intvl 1s, length 20
> >> 
> >> Mar 24 11:03:44 Zero-white Keepalived_vrrp[17338]: bogus VRRP packet
> >> received on eth0 !!!
> >> Mar 24 11:03:44 Zero-white Keepalived_vrrp[17338]: VRRP_Instance(LAN)
> >> Dropping received VRRP packet...
> >> Mar 24 11:03:44 Zero-white Keepalived_vrrp[17338]: VRRP_Instance(LAN)
> >> IPSEC-AH : sequence number 17800775 already proceeded. Packet dropped.
> >> 
> >> Local(17800812)
> >> Mar 24 11:03:44 Zero-white Keepalived_vrrp[17338]: bogus VRRP packet
> >> received on eth0 !!!
> >> Mar 24 11:03:44 Zero-white Keepalived_vrrp[17338]: VRRP_Instance(LAN)
> >> Dropping received VRRP packet...
> >> Mar 24 11:03:44 Zero-white Keepalived_vrrp[17338]: VRRP_Instance(LAN)
> >> IPSEC-AH : sequence number 17800775 already proceeded. Packet dropped.
> >> 
> >> Local(17800813)
> >> 
> >> These are just samples, so don't mind the "Local" sequence number
> >> stated
> >> in logs - I've got plenty of them. Though number stated on tcpdump and
> >> 
> >> "already processed number" in logs matches.
> >> The problem is floating - but happens frequently (couple of times per
> >> day). I can't figure out what triggers it and why does keepalived
> >> consider it's own sent packets as received (I can see them received on
> >> 
> >> my box in iptables raw table when doing trace - however tcpdump
> >> doesn't
> >> show them as received).
> >> I've noticed this problem a couple of weeks ago, was nothing similar
> >> before. If to talk about what was done with the box recently - I
> >> installed openvpn server on it. Later I tried searching the web and
> >> found some info that keepalived is not really capable of working with
> >> openvpn on one box cause it doesn't like hotplugging interfaces which
> >> openvpn does (tun interfaces). However even if I stop openvpn server
> >> the
> >> problem still persists. Is this really so and openvpn can't be used on
> >> 
> >> the same box with keepalived?
> >> I'm using keepalived 1.2.13 on Debian 7 with 3.16 kernel from
> >> backports.
> >> Openvpn version is 2.3.2 (if it is important).
> >> My keepalived is below:
> >> vrrp_instance LAN {
> >>  state BACKUP
> >>  interface eth0
> >>  virtual_router_id 7
> >>  priority 200
> >>  advert_int 1
> >>  garp_master_delay 1
> >>  #nopreempt
> >>  preempt
> >>  preempt_delay 2
> >>  notify_fault "/etc/keepalived/gw_vrrp_master_down"
> >>  notify_backup "/etc/keepalived/gw_vrrp_master_down"
> >>  notify_master "/etc/keepalived/gw_vrrp_master_up"
> >> authentication {
> >>  auth_type AH
> >>  auth_pass 12345
> >> }
> >> virtual_ipaddress {
> >>  10.1.64.155
> >> }
> >> }
> >> 
> >> Any help is appreciated. Thanks in advance.
> >> 
> >>  It appears that the packets are the same packet that for some reason
> >> is being reported as being received 4 times (there is a 60
> >> micro-second interval from the first to the last). This suggests to me
> >> that it is not keepalived sending the packets 4 times, but for some
> >> reason 1 packet is being reported 4 times as being received, which is
> >> presumably either due to some networking configuration or something
> >> happening in your kernel. It's probably worth looking in all your
> >> system logs at the time this problem happens to see if there is
> >> anything else happening at the same time. Did installing openvpn
> >> server change some other aspect of your system configuration so that
> >> even when not running the server you have a different configuration
> >> from before?
> >> 
> >>  Your version of keepalived is very old - some 16 versions behind the
> >> current version. If would be worth upgrading to version 1.3.5, since
> >> there have been hundreds of patches since your version.
> >> 
> >>  There is indeed an issue of keepalived not fully supporting
> >> hotplugging; it is something that I plan to add in the near future.
> >> However, if keepalived isn't configured to use any of the openvpn
> >> interfaces, then it shouldn't be a problem for keepalived (I'm talking
> >> about recent versions of keepalived here; I don't know about v1.2.13).
> >> 
> >>  Are you in a position to try uninstalling openvpn and seeing if the
> >> problem persists?
> >> 
> >>  Quentin Armitage
> > 
> > 
> > Hi Quentin!
> > 
> > Thanks for your reply.
> > 
> > Well, the box serves as the router/firewall, has asterisk and dhcpd
> > running as well as it had ipsec (strongswan) which is now turned off.
> > And openvpn now of course.
> > 
> > System logs don't show something special exactly prior to the issue -
> > some dhcp leases, tftp requests from IP phones and so on. Turning off
> > openvpn doesn't seem to help. Except for firewall configuration (adding
> > accept udp/1194 on input + adding rules between LAN and openvpn IP 
> > pool)
> > no other systems settings were altered during openvpn setup.
> > 
> > Keepalived runs on physical interface, it doesn't run on tun interfaces
> > of course. I can try uninstalling openvpn in fact it is now some kind 
> > of
> > testing on my box. So i'll try it and report.
> > 
> > Also I'll try to upgrade keepalived - 1.2.13 is just the version in
> > Debian 8 repositories (also installed it from backports just as the 
> > 3.16
> > kernel).
> > 
> > Probably I'll also try to upgrade my whole debian box to debian 8 - I
> > have seen problems with some software when some backported packages
> > (especially kernel) are installed in the system. But this option will
> > probably be the last - cause it obviously inflicts the services the box
> > provides and I'll need to get a maintenance window for it.
> > 
> > Thanks a lot for clues, I'll try and get back with the results.
> 
> Hi again guys!
> 
> Sorry for the delay, was a bit busy here.
> 
> I have installed fresh debian 8 on a testing machine, deployed openvpn 
> server and installed keepalived 1.3.5 as you suggested. Still I face the 
> same problem here. Log of the daemon startup and the bogus packet 
> errors:
> 
> Apr 25 09:06:17 NODE2 systemd[1]: Starting LVS and VRRP High 
> Availability Monitor...
> Apr 25 09:06:17 NODE2 Keepalived[3354]: Starting Keepalived v1.3.5 
> (03/19,2017), git commit v1.3.5-6-g6fa32f2
> Apr 25 09:06:17 NODE2 Keepalived[3354]: Unable to resolve default script 
> username 'keepalived_script' - ignoring
> Apr 25 09:06:17 NODE2 Keepalived[3354]: Opening file 
> '/etc/keepalived/keepalived.conf'.
> Apr 25 09:06:17 NODE2 systemd[1]: PID file 
> /var/run/keepalived/keepalived.pid not readable (yet?) after start.
> Apr 25 09:06:17 NODE2 Keepalived[3355]: Starting Healthcheck child 
> process, pid=3356
> Apr 25 09:06:17 NODE2 Keepalived[3355]: Starting VRRP child process, 
> pid=3357
> Apr 25 09:06:17 NODE2 Keepalived_vrrp[3357]: Registering Kernel netlink 
> reflector
> Apr 25 09:06:17 NODE2 Keepalived_healthcheckers[3356]: Initializing ipvs
> Apr 25 09:06:17 NODE2 Keepalived_vrrp[3357]: Registering Kernel netlink 
> command channel
> Apr 25 09:06:17 NODE2 Keepalived_vrrp[3357]: Registering gratuitous ARP 
> shared channel
> Apr 25 09:06:17 NODE2 Keepalived_vrrp[3357]: Opening file 
> '/etc/keepalived/keepalived.conf'.
> Apr 25 09:06:17 NODE2 Keepalived_healthcheckers[3356]: Opening file 
> '/etc/keepalived/keepalived.conf'.
> Apr 25 09:06:17 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> removing protocol VIPs.
> Apr 25 09:06:17 NODE2 Keepalived_vrrp[3357]: Using LinkWatch kernel 
> netlink reflector...
> Apr 25 09:06:17 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> Entering BACKUP STATE
> Apr 25 09:06:17 NODE2 Keepalived_vrrp[3357]: VRRP sockpool: [ifindex(2), 
> proto(51), unicast(0), fd(10,11)]
> Apr 25 09:06:20 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> Transition to MASTER STATE
> Apr 25 09:06:21 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> Entering MASTER STATE
> Apr 25 09:06:21 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) setting 
> protocol VIPs.
> Apr 25 09:06:21 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:21 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> Sending/queueing gratuitous ARPs on eth0 for 10.1.64.13
> Apr 25 09:06:21 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:21 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:21 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:21 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:22 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:22 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> Sending/queueing gratuitous ARPs on eth0 for 10.1.64.13
> Apr 25 09:06:22 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:22 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:22 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:22 NODE2 Keepalived_vrrp[3357]: Sending gratuitous ARP on 
> eth0 for 10.1.64.13
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> IPSEC-AH : sequence number 36 already proceeded. Packet dropped. 
> Local(37)
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: bogus VRRP packet received 
> on eth0 !!!
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> Dropping received VRRP packet...
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> IPSEC-AH : sequence number 36 already proceeded. Packet dropped. 
> Local(38)
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: bogus VRRP packet received 
> on eth0 !!!
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> Dropping received VRRP packet...
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> IPSEC-AH : sequence number 36 already proceeded. Packet dropped. 
> Local(39)
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: bogus VRRP packet received 
> on eth0 !!!
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> Dropping received VRRP packet...
> Apr 25 09:06:55 NODE2 Keepalived_vrrp[3357]: VRRP_Instance(TEST) 
> IPSEC-AH : sequence number 36 already proceeded. Packet dropped. 
> Local(40)
> 
> Here is the keepalived version:
> 
> /usr/local/keepalived/sbin/keepalived -v
> Keepalived v1.3.5 (03/19,2017), git commit v1.3.5-6-g6fa32f2
> 
> Copyright(C) 2001-2017 Alexandre Cassen, <[email protected]>
> 
> Build options:  PIPE2 IPV4_DEVCONF IF_H_LINK_H_COLLISION LIBNL3 
> FRA_OIFNAME FRA_SUPPRESS_PREFIXLEN FRA_SUPPRESS_IFGROUP RTAX_QUICKACK 
> LINUX_NET_IF_H_COLLISION LVS LIBIPVS_NETLINK VRRP VRRP_AUTH VRRP_VMAC 
> SOCK_NONBLOCK SOCK_CLOEXEC FIB_ROUTING SNMP SNMP_KEEPALIVED SNMP_CHECKER 
> SO_MARK
> 
> Kernel version:
> 
> root@NODE2:~# uname -a
> Linux NODE2 3.16.0-4-686-pae #1 SMP Debian 3.16.36-1+deb8u1 (2016-09-03) 
> i686 GNU/Linux
> 
> And keepalived config:
> 
> vrrp_instance TEST {
>          state BACKUP
>          interface eth0
>          virtual_router_id 73
>          priority 200
>          advert_int 1
>          garp_master_delay 1
>          #nopreempt
>          preempt
>          preempt_delay 2
> #        notify_fault "/etc/keepalived/gw_vrrp_master_down"
> #        notify_backup "/etc/keepalived/gw_vrrp_master_down"
> #        notify_master "/etc/keepalived/gw_vrrp_master_up"
> authentication {
>          auth_type AH
>          auth_pass 12345
> }
> virtual_ipaddress {
>          10.1.64.13
> }
> }
> 
> I'll also try removing openvpn from my test machine and try once more.
> 
> 

I'm convinced this is something going on within your kernel/network
configuration or within your network (could it be that a switch is for
some reason looping back packets, or that a layer 2 loop is forming in
your network?). Since keepalived is not normally reporting bogus
received packets, but only does so occasionally, it suggests that it is
something happening elsewhere from keepalived that is causing the issue.

You could try a patch something like the following to demonstrate
whether it is keepalived sending multiple duplicate packets:
diff --git a/keepalived/vrrp/vrrp.c b/keepalived/vrrp/vrrp.c
index 722cdf4..2621690 100644
--- a/keepalived/vrrp/vrrp.c
+++ b/keepalived/vrrp/vrrp.c
@@ -1121,6 +1121,7 @@ vrrp_send_pkt(vrrp_t * vrrp, struct
sockaddr_storage *addr)
                vrrp_build_ancillary_data(&msg, cbuf, src);
        }

+log_message(LOG_INFO, "Sending advert with seq no %d",
vrrp->ipsecah_counter->seq_number);
        /* Send the packet */
        return sendmsg(vrrp->fd_out, &msg, (addr) ? 0 : MSG_DONTROUTE);
 }

and then the logs will show whether keepalived is sending adverts with
the same sequence number multiple times.

Another way to possibly see what is going on is to add the following
iptables entries:
    iptables -t raw -I PREROUTING -p 112 -j LOG --log-prefix "VRRP in: "
    iptables -t raw -I OUTPUT -p 112 -j LOG --log-prefix "VRRP out: "
These should log all sent and received VRRP packets, identifying the
interfaces they are being sent/received on.

There does appear to be a problem in the code in keepalived/vrrp/vrrp.c,
but it isn't related to you problem, at:

> /*
>          * then proceed with the sequence number to prevent against replay attack.
>          * For inbound processing, we increment seq_number counter to audit
>          * sender counter.
>          */
>         vrrp->ipsecah_counter->seq_number++;
>         if (ntohl(ah->seq_number) >= vrrp->ipsecah_counter->seq_number ||
>             vrrp->sync
> #ifdef _HAVE_VRRP_VMAC_
>             || __test_bit(VRRP_VMAC_BIT, &vrrp->vmac_flags)
> #endif
>                                                         ) {
>                 vrrp->ipsecah_counter->seq_number = ntohl(ah->seq_number);
>         } else {
>                 log_message(LOG_INFO, "VRRP_Instance(%s) IPSEC-AH : sequence number %d"
>                                         " already processed. Packet dropped. Local(%d)",
>                                         vrrp->iname, ntohl(ah->seq_number),
>                                         vrrp->ipsecah_counter->seq_number);
>                 ++vrrp->stats->auth_failure;
>                 return 1;
>         }

where I think vrrp->ipsecah_counter->seq_number shouldn't be incremented
if the packet isn't valid - I'll have a look at this in the next few
days.

I appreciate that this isn't a solution to your problem, but it should
allow us to understand further where the problem is occurring.

Quentin

------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot

_______________________________________________
Keepalived-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/keepalived-devel