HSRP Flapping BTW Two Core Switches

saviolabao2 · ‎12-01-2016

Hello Guys,

We meet a problem on the HSRP between our two core switches whose model is WS-C3750X-12S-S with IOS version 15.0(2)SE4 on both sides.

We found that the HSRP of all the VLANs are flapping all the time every hour with an example as below:

Nov 16 09:33:05.095 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 16 09:33:06.035 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 16 13:33:07.660 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 16 13:33:07.660 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 16 13:33:08.700 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 16 15:33:08.927 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 16 15:33:08.935 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 16 15:33:09.967 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 16 17:33:10.185 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 16 17:33:10.193 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 16 17:33:11.234 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 16 21:33:12.734 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 16 21:33:12.743 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 16 21:33:13.724 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 17 04:05:56.509 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 17 04:05:56.517 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 17 04:05:57.549 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 17 04:33:17.266 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 17 04:33:17.274 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 17 04:33:18.231 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 17 05:33:17.927 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 17 05:33:17.944 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 17 05:33:18.917 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 17 09:33:20.476 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 17 09:33:20.484 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 17 09:33:21.516 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 17 14:33:23.642 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active
Nov 17 14:33:23.658 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Active -> Speak
Nov 17 14:33:24.682 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Speak -> Standby
Nov 17 18:33:26.404 Paris: %HSRP-5-STATECHANGE: Vlan224 Grp 1 state Standby -> Active

It is weird that most of the time it happens around 30-35 minute within one hour. There's no complaint from user side about any network interrupt.

Here's the configuration about HSRP:

interface Vlan224
standby 1 ip 1.1.1.254
standby 1 timers msec 300 msec 900
standby 1 preempt delay minimum 45
arp timeout 1200

I opened "debug standby" on one of the switches and here's the log before and after one flap:

Dec 1 08:18:29.936 Paris: HSRP: Vl228 Grp 1 Hello in 10.132.228.251 Active pri 100 vIP 10.132.228.254
Dec 1 08:18:29.936 Paris: HSRP: Vl228 Grp 1 Hello out 10.132.228.250 Standby pri 90 vIP 10.132.228.254
Dec 1 08:18:29.936 Paris: HSRP: Vl316 Grp 1 Hello out 10.132.226.132 Standby pri 90 vIP 10.132.226.134
Dec 1 08:18:29.936 Paris: HSRP: Vl224 Grp 1 Hello out 10.132.224.250 Standby pri 90 vIP 10.132.224.254
Dec 1 08:18:29.945 Paris: HSRP: Vl316 Grp 1 Hello in 10.132.226.133 Active pri 100 vIP 10.132.226.134
Dec 1 08:18:29.945 Paris: HSRP: Vl920 Grp 1 Hello in 10.132.226.61 Active pri 100 vIP 10.132.226.62
Dec 1 08:18:29.945 Paris: HSRP: Vl224 Grp 1 Hello in 10.132.224.251 Active pri 100 vIP 10.132.224.254
Dec 1 08:18:30.800 Paris: HSRP: Vl920 Grp 1 Hello out 10.132.226.60 Standby pri 90 vIP 10.132.226.62
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Grp 1 Hello out 10.132.228.250 Standby pri 90 vIP 10.132.228.254
Dec 1 08:18:30.809 Paris: HSRP: Vl316 Grp 1 Hello out 10.132.226.132 Standby pri 90 vIP 10.132.226.134
Dec 1 08:18:30.809 Paris: HSRP: Vl224 Grp 1 Hello out 10.132.224.250 Standby pri 90 vIP 10.132.224.254
Dec 1 08:18:30.809 Paris: HSRP: Vl920 Grp 1 Hello out 10.132.226.60 Standby pri 90 vIP 10.132.226.62
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Grp 1 Hello out 10.132.228.250 Standby pri 90 vIP 10.132.228.254
Dec 1 08:18:30.809 Paris: HSRP: Vl316 Grp 1 Hello out 10.132.226.132 Standby pri 90 vIP 10.132.226.134
Dec 1 08:18:30.809 Paris: HSRP: Vl224 Grp 1 Hello out 10.132.224.250 Standby pri 90 vIP 10.132.224.254
Dec 1 08:18:30.809 Paris: HSRP: Vl920 Grp 1 Hello out 10.132.226.60 Standby pri 90 vIP 10.132.226.62
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Grp 1 Hello out 10.132.228.250 Standby pri 90 vIP 10.132.228.254
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Grp 1 Standby: c/Active timer expired (10.132.228.251)
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Grp 1 Active router is local, was 10.132.228.251
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Nbr 10.132.228.251 no longer active for group 1 (Standby)
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Nbr 10.132.228.251 Was active or standby - start passive holddown
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Grp 1 Standby router is unknown, was local
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Grp 1 Standby -> Active
Dec 1 08:18:30.809 Paris: %HSRP-5-STATECHANGE: Vlan228 Grp 1 state Standby -> Active
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Interface adv out, Active, active 1 passive 0
Dec 1 08:18:30.809 Paris: HSRP: Vl228 Grp 1 Redundancy "hsrp-Vl228-1" state Standby -> Active
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Grp 1 Hello out 10.132.228.250 Active pri 90 vIP 10.132.228.254
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Grp 1 Added 10.132.228.254 to ARP (0000.0c07.ac01)
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Grp 1 Activating MAC 0000.0c07.ac01
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Grp 1 Adding 0000.0c07.ac01 to MAC address filter
Dec 1 08:18:30.817 Paris: HSRP: Vl316 Grp 1 Hello out 10.132.226.132 Standby pri 90 vIP 10.132.226.134
Dec 1 08:18:30.817 Paris: HSRP: Vl224 Grp 1 Hello out 10.132.224.250 Standby pri 90 vIP 10.132.224.254
Dec 1 08:18:30.817 Paris: HSRP: Vl228 IP Redundancy "hsrp-Vl228-1" standby, local -> unknown
Dec 1 08:18:30.817 Paris: HSRP: Vl228 IP Redundancy "hsrp-Vl228-1" update, Standby -> Active
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Grp 1 Hello in 10.132.228.251 Active pri 100 vIP 10.132.228.254
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Grp 1 Active router is 10.132.228.251, was local
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Nbr 10.132.228.251 is no longer passive
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Nbr 10.132.228.251 active for group 1
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Grp 1 Active: g/Hello rcvd from higher pri Active router (100/10.132.228.251)
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Grp 1 Active -> Speak
Dec 1 08:18:30.817 Paris: %HSRP-5-STATECHANGE: Vlan228 Grp 1 state Active -> Speak
Dec 1 08:18:30.817 Paris: HSRP: Vl228 Interface adv out, Passive, active 0 passive 1
Dec 1 08:18:30.825 Paris: HSRP: Vl228 Grp 1 Redundancy "hsrp-Vl228-1" state Active -> Speak
Dec 1 08:18:30.825 Paris: HSRP: Vl228 Grp 1 Resign out 10.132.228.250 Speak pri 90 vIP 10.132.228.254
Dec 1 08:18:30.825 Paris: HSRP: Vl228 Grp 1 Removed 10.132.228.254 from ARP
Dec 1 08:18:30.825 Paris: HSRP: Vl228 Grp 1 Deactivating MAC 0000.0c07.ac01
Dec 1 08:18:30.825 Paris: HSRP: Vl228 Grp 1 Removing 0000.0c07.ac01 from MAC address filter
Dec 1 08:18:30.825 Paris: HSRP: Vl228 Grp 1 Hello out 10.132.228.250 Speak pri 90 vIP 10.132.228.254
Dec 1 08:18:30.825 Paris: HSRP: Vl228 IP Redundancy "hsrp-Vl228-1" update, Active -> Speak
Dec 1 08:18:30.825 Paris: HSRP: Vl316 Grp 1 Hello in 10.132.226.133 Active pri 100 vIP 10.132.226.134
Dec 1 08:18:30.825 Paris: HSRP: Vl920 Grp 1 Hello in 10.132.226.61 Active pri 100 vIP 10.132.226.62
Dec 1 08:18:30.825 Paris: HSRP: Vl224 Grp 1 Hello in 10.132.224.251 Active pri 100 vIP 10.132.224.254
Dec 1 08:18:30.825 Paris: HSRP: Vl228 Grp 1 Hello in 10.132.228.251 Active pri 100 vIP 10.132.228.254

The time of the flap is "08:18:30.809" and the last hello in before is at "08:18:29.936". the first hello in after it is at "08:18:30.817", so we can see that the time between the two hello in is only 881 ms. It is less than 900 ms which is the hold time I configured. Does that make sense?

Did anyone meet this kind of problem before?

Thanks in advance for your patience and help.

Regards,

Savi

Mark Malone · ‎12-01-2016

did you check STP to see if that's causing it and there are constant changes at l2 same time

show spanning-tree detail | inc ieee|occurr|from|is exec

Have you tired increasing the timers slightly to see if it stabilizes

You could try add this as well ...standby delay minimum 30 reload 60

"We recommend that all HSRP devices have the standby delay minimum reload configured with a minimum delay time of 30 seconds and a minimum reload time of 60 seconds.

The delay will be cancelled if an HSRP packet is received on an interface.

The standby delay minimum reload interface configuration command delays HSRP groups from initializing for the specified time after the interface comes up. "