EEM config & Track delay

[Ven Taylor]

We have two iBGP peers with their own separate eBGP (Internet) peers.

We use them as an HSRP pair (over an L2 trunk) for our redundant Internet.

I've created an EEM script that will have the "secondary" router track the "primary" router's HSRP interface to ensure it's still up.

If the link goes down, the router immediately removes all of its iBGP static routes to avoid a routing black hole.

When the link comes back up, the secondary router re-adds the iBGP static routes.

The script works fine, but the maximum delay on the ip sla track command has a maximum of 180 seconds.

Since we're talking BGP, this short delay could wreak havoc if an Internet link is flapping or something.

Here's the track command:

track 1 ip sla 1 reachability

default-state up

delay down 30 up 180

I'm trying to think of a way to make it wait longer than 180 seconds.  (900 seconds would be ideal to ensure the issue has been resolved before re-establishing the static routes.

Can anyone think of a way to increase the delay using the EEM commands?  The track command is too limited here.

Thanks!

Ven

[Joe Clarke · Accepted solution]

Don't rely on track.  Remove the up delay, and have your EEM policy that detects the up condition install a second EEM policy that counts down from 900.  If that policy is allowed to hit 0, it will reconfigure the peers.  If not, then the "down" policy will remove it.  I call this "nesting" EEM policies.  Your "up" policy would look something like:

event manager environment q "

!

event manager applet ipsla-up

event track 1 state up

action 1.0 cli command "enable"

action 2.0 cli command "config t"

action 3.0 cli command "event manager applet add-ibgp"

action 3.1 cli command "event timer countdown time 900"

action 3.2 cli command "action 1.0 cli command enable"

action 3.3 cli command "action 2.0 cli command $q config t$q"

action 3.4 cli command "action 3.0 cli command ADD_BGP_PEERS"

action 3.5 cli command "action 4.0 cli command end"

action 4.0 cli command "end"

Then add some code to your "down" applet to remove the "add-ibgp" policy if the link goes down again.  Make sense?

[Ven Taylor]

Joseph:

You know, I really don't get it.

Here's what I've got:

no event manager session cli username "EEM"

no event manager applet track-bgp-down authorization bypass

no event manager applet track-bgp-up authorization bypass

!

event manager session cli username "EEM"

event manager applet track-bgp-down authorization bypass

event track 1 state down

action 100 cli command "enable"

action 101 cli command "conf t"

action 105 cli command "no ip route 10.101.16.101 255.255.255.255 163.230.254.69"

action 110 cli command "no ip route 10.101.16.112 255.255.255.255 163.230.254.69"

action 115 cli command "no ip route 163.230.0.0 255.255.0.0 163.230.254.69"

action 120 cli command "no ip route 163.230.250.0 255.255.255.0 163.230.254.69"

action 125 cli command "no ip route 216.54.43.224 255.255.255.224 163.230.254.69"

action 130 cli command "end"

action 135 syslog priority notifications msg "SCP iBGP static routes deleted due to vlan200 failure"

event manager applet track-bgp-up authorization bypass

event track 1 state up

action 100 cli command "enable"

action 105 cli command "conf t"

action 107 cli command "event timer countdown time 900"

action 110 cli command "ip route 10.101.16.101 255.255.255.255 163.230.254.69"

action 115 cli command "ip route 10.101.16.112 255.255.255.255 163.230.254.69"

action 120 cli command "ip route 163.230.0.0 255.255.0.0 163.230.254.69"

action 125 cli command "ip route 163.230.250.0 255.255.255.0 163.230.254.69"

action 130 cli command "ip route 216.54.43.224 255.255.255.224 163.230.254.69"

action 135 cli command "end"

action 140 syslog priority notifications msg "SCP iBGP static routes re-added - vlan200 UP"

!

The problem is, the countdown time 900 doesn't seem to do anything.  I shut down the interface, then turn it back up, then watch the log.

To test, I put in syslog messages before and afte the countdown time and expected to see a 15 minute timestamp difference between them, but I didn't.  They were only milliseconds apart.  That tells me the countdown didn't happen.

What do you think?

[Joe Clarke · Accepted solution]

Then this should work.

event manager environment q "

!

event manager applet track-bgp-down authorization bypass

event track 1 state down

action 100 cli command "enable"

action 101 cli command "conf t"

action 105 cli command "no ip route 10.101.16.101 255.255.255.255 163.230.254.69"

action 110 cli command "no ip route 10.101.16.112 255.255.255.255 163.230.254.69"

action 115 cli command "no ip route 163.230.0.0 255.255.0.0 163.230.254.69"

action 120 cli command "no ip route 163.230.250.0 255.255.255.0 163.230.254.69"

action 125 cli command "no ip route 216.54.43.224 255.255.255.224 163.230.254.69"

action 126 cli command "no event manager applet add-ibgp"

action 130 cli command "end"

action 135 syslog priority notifications msg "SCP iBGP static routes deleted due to vlan200 failure"

!

event manager applet track-bgp-up authorization bypass

event track 1 state up

action 100 cli command "enable"

action 105 cli command "conf t"

action 106 cli command "event manager applet add-ibgp"

action 107 cli command "event timer countdown time 900"

action 108 cli command "action 1.0 cli command enable"

action 109 cli command "action 2.0 cli command $q config t$q"

action 110 cli command "action 3.0 cli command $q ip route 10.101.16.101 255.255.255.255 163.230.254.69$q"

action 115 cli command "action 4.0 cli command $q ip route 10.101.16.112 255.255.255.255 163.230.254.69$q"

action 120 cli command "action 5.0 cli command $q ip route 163.230.0.0 255.255.0.0 163.230.254.69$q"

action 125 cli command "action 6.0 cli command $q ip route 163.230.250.0 255.255.255.0 163.230.254.69$q"

action 130 cli command "action 7.0 cli command $q ip route 216.54.43.224 255.255.255.224 163.230.254.69$q"

action 131 cli command "action 8.0 cli command end"

action 135 cli command "end"

action 140 syslog priority notifications msg "SCP iBGP static routes re-added - vlan200 UP"

[Ven Taylor]

Joseph:

I tried that, but all it did was create the new applet "add-ibgp" but didn't actually run the applet because the routes are still gone.

Should there be something that runs the applet after it's created?

Ven

[Joe Clarke]

Once created, the add-ibgp applet will run after 900 seconds.  Then it will unconfigure itself.  This is so you're sure that the network has been stable for 15 minutes.  If it goes down again, the "down" applet will unconfigure the add-ibgp applet thus preventing its timer from reaching 0.

[Ven Taylor]

That makes sense, but it didn't do anything after the 15-minute wait period.

In fact, it's been a few hours now and the routes are still not back.  (lab)

Any thoughts?

Ven

[Joe Clarke]

Post your full EEM config.  I have a feeling something was left out.

[Ven Taylor]

Here it is.  I've made a change to the actual commands being run because I found killing the external neighbor works better than deleting and adding routes.

<----->

track 1 ip sla 1 reachability

default-state up

delay down 30 up 30

!

!

ip sla 1

icmp-echo 163.230.254.66 source-ip 163.230.254.67

request-data-size 128

tos 5

threshold 120

timeout 150

frequency 20

ip sla schedule 1 life forever start-time now

!

!

event manager environment q "

event manager session cli username "EEM"

event manager applet track-bgp-down authorization bypass

event track 1 state down

action 100 cli command "enable"

action 101 cli command "conf t"

action 105 cli command "router bgp 27336"

action 110 cli command "neighbor 152.179.202.81 shutdown"

action 115 cli command "no event manager applet add-ibgp"

action 120 cli command "end"

action 125 syslog priority notifications msg "SCP/Verizon eBGP neighbor shutdown due to vlan200 failure"

event manager applet track-bgp-up authorization bypass

event track 1 state up

action 100 cli command "enable"

action 105 cli command "conf t"

action 110 cli command "event manager applet add-ibgp"

action 115 cli command "event timer countdown time 300"

action 120 cli command "action 1.0 cli command enable"

action 125 cli command "action 2.0 cli command $q config t$q"

action 130 cli command "action 3.0 cli command $q router bgp 27336$q"

action 135 cli command "action 4.0 cli command $q no neighbor 152.179.202.81 shutdown$q"

action 140 cli command "action 8.0 cli command end"

action 145 cli command "end"

action 150 syslog priority notifications msg "SCP/Verizon eBGP neighbor re-added - vlan200 UP"

event manager applet add-ibgp

event timer countdown time 300

action 1.0 cli command "enable"

action 2.0 cli command " config t"

action 3.0 cli command " router bgp 27336"

action 4.0 cli command " no neighbor 152.179.202.81 shutdown"

action 8.0 cli command "end"

!

end

[Joe Clarke]

This looks good.  In fact, with the add-ibgp applet there, it should run those exact commands once after 300 seconds elapsed from the time the applet was configured.  What you can do is check "show event manager history events" to see if it ran.  If so, but the neighbor is not being re-enabled, enable "debug event manager action cli" and redo the whole test scenario.  Post the debug output.

[Ven Taylor]

Looks like it's calling the add-ibgp, but it stops after the config t.

scp1001-a5t-3#

*Sep 25 15:26:23.680: %TRACKING-5-STATE: 1 ip sla 1 reachability Up->Down

*Sep 25 15:26:23.680: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : CTL : cli_open called.

*Sep 25 15:26:23.681: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : OUT : scp1001-a5t-3>

*Sep 25 15:26:23.681: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : IN  : scp1001-a5t-3>enable

*Sep 25 15:26:23.691: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : OUT : scp1001-a5t-3#

*Sep 25 15:26:23.691: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : IN  : scp1001-a5t-3#conf t

*Sep 25 15:26:23.801: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : OUT : Enter configuration commands, one per line.  End with CNTL/Z.

*Sep 25 15:26:23.801: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config)#

*Sep 25 15:26:23.801: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config)#router bgp 27336

*Sep 25 15:26:23.911: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-router)#

*Sep 25 15:26:23.911: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-router)#neighbor 152.179.202.81 shutdown

*Sep 25 15:26:24.021: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-router)#

*Sep 25 15:26:24.021: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-router)#no event manager applet add-ibgp

*Sep 25 15:26:24.131: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config)#

*Sep 25 15:26:24.131: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config)#end

*Sep 25 15:26:24.138: %SYS-5-CONFIG_I: Configured from console by EEM on vty0 (EEM:track-bgp-down)

*Sep 25 15:26:24.141: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : OUT : scp1001-a5t-3#

*Sep 25 15:26:24.141: %HA_EM-5-LOG: track-bgp-down: SCP iBGP static routes deleted due to vlan200 failure

*Sep 25 15:26:24.141: %HA_EM-6-LOG: track-bgp-down : DEBUG(cli_lib) : : CTL : cli_close called.

*Sep 25 15:26:24.141: tty is now going through its death sequence

*Sep 25 15:26:31.530: %BGP-5-ADJCHANGE: neighbor 163.230.254.66 Down BGP Notification sent

*Sep 25 15:26:31.530: %BGP-3-NOTIFICATION: sent to neighbor 163.230.254.66 4/0 (hold time expired) 0 bytes

*Sep 25 15:26:31.530: %BGP_SESSION-5-ADJCHANGE: neighbor 163.230.254.66 IPv4 Unicast topology base removed from session  BGP Notification sent

*Sep 25 15:26:47.964: %LINK-3-UPDOWN: Interface GigabitEthernet0/0/1, changed state to up

*Sep 25 15:26:48.964: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/0/1, changed state to up

*Sep 25 15:26:47.964: %LINK-3-UPDOWN: SIP0/0: Interface GigabitEthernet0/0/1, changed state to up

*Sep 25 15:26:49.909: %BGP-5-ADJCHANGE: neighbor 163.230.254.66 Up

*Sep 25 15:27:23.680: %TRACKING-5-STATE: 1 ip sla 1 reachability Down->Up

*Sep 25 15:27:23.680: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : CTL : cli_open called.

*Sep 25 15:27:23.681: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3>

*Sep 25 15:27:23.681: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3>enable

*Sep 25 15:27:23.691: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3#

*Sep 25 15:27:23.691: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3#conf t

*Sep 25 15:27:23.701: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : Enter configuration commands, one per line.  End with CNTL/Z.

*Sep 25 15:27:23.701: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config)#

*Sep 25 15:27:23.701: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config)#event manager applet add-ibgp

*Sep 25 15:27:23.811: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-applet)#

*Sep 25 15:27:23.811: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-applet)#event timer countdown time 300

*Sep 25 15:27:23.921: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-applet)#

*Sep 25 15:27:23.921: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-applet)#action 1.0 cli command enable

*Sep 25 15:27:24.031: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-applet)#

*Sep 25 15:27:24.031: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-applet)#action 2.0 cli command " config t"

*Sep 25 15:27:24.141: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-applet)#

*Sep 25 15:27:24.141: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-applet)#action 3.0 cli command " router bgp 27336"

*Sep 25 15:27:24.251: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-applet)#

*Sep 25 15:27:24.251: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-applet)#action 4.0 cli command " no neighbor 152.179.202.81 shutdown"

*Sep 25 15:27:24.361: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-applet)#

*Sep 25 15:27:24.361: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-applet)#action 8.0 cli command end

*Sep 25 15:27:24.471: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3(config-applet)#

*Sep 25 15:27:24.471: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : IN  : scp1001-a5t-3(config-applet)#end

*Sep 25 15:27:24.474: %SYS-5-CONFIG_I: Configured from console by EEM on vty0 (EEM:track-bgp-up)

*Sep 25 15:27:24.481: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : OUT : scp1001-a5t-3#

*Sep 25 15:27:24.481: %HA_EM-5-LOG: track-bgp-up: SCP iBGP static routes re-added - vlan200 UP

*Sep 25 15:27:24.481: %HA_EM-6-LOG: track-bgp-up : DEBUG(cli_lib) : : CTL : cli_close called.

*Sep 25 15:27:24.481: tty is now going through its death sequence

*Sep 25 15:27:42.058: %HSRP-5-STATECHANGE: GigabitEthernet0/0/1 Grp 1 state Speak -> Standby

*Sep 25 15:32:24.474: %HA_EM-6-LOG: add-ibgp : DEBUG(cli_lib) : : CTL : cli_open called.

*Sep 25 15:32:24.475: %HA_EM-6-LOG: add-ibgp : DEBUG(cli_lib) : : OUT : scp1001-a5t-3>

*Sep 25 15:32:24.475: %HA_EM-6-LOG: add-ibgp : DEBUG(cli_lib) : : IN  : scp1001-a5t-3>enable

*Sep 25 15:32:24.485: %HA_EM-6-LOG: add-ibgp : DEBUG(cli_lib) : : OUT : scp1001-a5t-3#

*Sep 25 15:32:24.485: %HA_EM-6-LOG: add-ibgp : DEBUG(cli_lib) : : IN  : scp1001-a5t-3# config t

*Sep 25 15:32:44.500: %HA_EM-6-LOG: add-ibgp : DEBUG(cli_lib) : : CTL : cli_close called.

*Sep 25 15:32:46.496: tty is now going through its death sequence

[Joe Clarke]

What version of IOS is this?  This looks like an interaction bug with AAA, but I can't say why it was working for the other applets.  The only difference is "config t" vs. "conf t" but the commands should both be fully expanded to "configure terminal" before being passed to the AAA server.

[Ven Taylor]

Joseph:

I'm running 15.1(2)S on an ASR1001.

I appreciate all your help here.  I'll push it off to TAC and see if they can tell me if there's a bug associated with this.

Ven

[Joe Clarke]

The bug I had in mind only affects very old IOS code.  You're not seeing that.  One thing you might try is adding the pattern keyword after the "config t" like:

action 125 cli command "action 2.0 cli command $q config t$q pattern .*"

That may force the applet to continue.

[Ven Taylor]

I figured it out.

The applet that was created required the authorization bypass.

action 110 cli command "event manager applet add-ibgp authorization bypass"  <-- 

Once I added that, it worked like a charm.

Thanks for your help Joseph!!