EEM - wait until interface fully up before processing?

[DazOG]

Hi

I have a 3750-X switch that has some PoE cameras and a controller attached.  I'm trying to make it so that the cameras are only powered when the controller is, because one isn't used without the other.  I have written two event applets that simply "shut" or "no shut" the relevant interfaces attached to the cameras, triggered by observing a syslog entry for the controller coming online.

The pertinent part of my config is as follows:

event manager applet CamsDOWN
event syslog pattern "%LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to down"
action 1.0 syslog msg "--- Controller is DOWN, shutting down cameras ---"
action 2.0 cli command "enable"
action 3.0 cli command "conf t"
action 4.0 cli command "int range gi2/0/28, gi2/0/30, gi2/0/32"
action 5.0 cli command "shut"
action 6.0 cli command "end"
action 7.0 syslog msg "--- Cameras shut down successfully ---"
!
event manager applet CamsUP
event syslog pattern "%LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to up"
action 1.0 syslog msg "--- Controller is UP, bringing up cameras ---"
action 2.0 cli command "enable"
action 3.0 cli command "conf t"
action 4.0 cli command "int range gi2/0/28, gi2/0/30, gi2/0/32"
action 5.0 cli command "no shut"
action 6.0 cli command "end"
action 7.0 syslog msg "--- Cameras turned on successfully ---"
!

This works ok, but the problem I have is that the controller flaps a bit when starting up, so the syslog lines trigger multiple times, meaning both applets fire more than once, so cameras are turned on and off again rapidly, before finally turning on properly.

The IOS software I'm running on my 3750-X (15.2(4)E10) does not support "event track" in the EEM configuration, which is why I'm looking for the syslog pattern instead.  Annoyingly, it does appear to support "track 5 interface GigabitEthernet2/0/3 line-protocol" along with the "carrier-delay" and "delay" settings, but I can't trigger off of this it seems - so I'm not sure what the point of it is?

Anyone have any thoughts about how I can workaround this?  Thanks in advance!

[MHM Cisco World]

Action x.x cli wait <time you want to wait then apply othet action>

MHM

[DazOG]

That won't work I don't think because both the "up" and "down" applets are being triggered more than once by the flapping interface.  Adding a delay to each instance of the applet won't stop it executing multiple times.

[MHM Cisco World]

as I mention you can use wait for eem interface up' to make it wait any action befor time you apply.

Second if you have flapping then use rate-limit which make your entire EEM run specific number per specific time.

MHM

[DazOG]

Thanks.

Where would those changes go in the applets I provided?

I also still don't understand why adding a "cli wait" command would make any difference when the "up" and "down" applets are running more than once when the controller comes online.  All it will do is make each instance of the applet execution take a bit longer, but it'll still run.

[balaji.bandi]

In addition what you said - that is Limitation of the switch, you can use TCL script to make more advanced level if you like.

I also still don't understand why adding a "cli wait" command would make any difference when the "up" and "down" applets are running more than once when the controller comes online.  All it will do is make each instance of the applet execution take a bit longer, but it'll still run.

Some time required time for further excuting steps, so wait time will be added - by default timer is 20, that need to increase if you need more time to run, if not script timeout occurs.

[DazOG]

Thanks.

20 seconds is more than enough time for the scripts to run.

I don't know if I am being clear enough.  When the controller device comes online, I see the following in my syslog:

Jan 15 10:56:07.258: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/3, changed state to up
Jan 15 10:56:08.264: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to up
Jan 15 10:56:08.281: %HA_EM-6-LOG: CamsUP: --- Controller is UP, bringing up cameras ---
Jan 15 10:56:08.751: %SYS-5-CONFIG_I: Configured from console by on vty1 (EEM:CamsUP)
Jan 15 10:56:08.851: %HA_EM-6-LOG: CamsUP: --- Cameras turned on successfully ---
Jan 15 10:56:09.424: %ILPOWER-7-DETECT: Interface Gi2/0/30: Power Device detected: IEEE PD (og-core-sw-2)
Jan 15 10:56:09.533: %ILPOWER-7-DETECT: Interface Gi2/0/32: Power Device detected: IEEE PD (og-core-sw-2)
Jan 15 10:56:09.808: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to down
Jan 15 10:56:09.833: %HA_EM-6-LOG: CamsDOWN: --- Controller is DOWN, shutting down cameras ---
Jan 15 10:56:10.596: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/28, changed state to down
Jan 15 10:56:10.621: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/30, changed state to down
Jan 15 10:56:10.638: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/32, changed state to down
Jan 15 10:56:09.718: %ILPOWER-5-POWER_GRANTED: Interface Gi2/0/30: Power granted (og-core-sw-2)
Jan 15 10:56:09.785: %ILPOWER-5-POWER_GRANTED: Interface Gi2/0/32: Power granted (og-core-sw-2)
Jan 15 10:56:10.823: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/3, changed state to down
Jan 15 10:56:11.703: %SYS-5-CONFIG_I: Configured from console by on vty1 (EEM:CamsDOWN)
Jan 15 10:56:11.762: %HA_EM-6-LOG: CamsDOWN: --- Cameras shut down successfully ---
Jan 15 10:56:13.532: %LINK-5-CHANGED: Interface GigabitEthernet2/0/28, changed state to administratively down
Jan 15 10:56:13.532: %LINK-5-CHANGED: Interface GigabitEthernet2/0/30, changed state to administratively down
Jan 15 10:56:13.549: %LINK-5-CHANGED: Interface GigabitEthernet2/0/32, changed state to administratively down
Jan 15 10:56:15.201: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/3, changed state to up
Jan 15 10:56:16.225: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to up
Jan 15 10:56:16.250: %HA_EM-6-LOG: CamsUP: --- Controller is UP, bringing up cameras ---
Jan 15 10:56:17.273: %SYS-5-CONFIG_I: Configured from console by on vty1 (EEM:CamsUP)
Jan 15 10:56:17.315: %HA_EM-6-LOG: CamsUP: --- Cameras turned on successfully ---
Jan 15 10:56:18.112: %ILPOWER-7-DETECT: Interface Gi2/0/30: Power Device detected: IEEE PD (og-core-sw-2)
Jan 15 10:56:18.255: %ILPOWER-7-DETECT: Interface Gi2/0/32: Power Device detected: IEEE PD (og-core-sw-2)
...

As you can see - when the controller is switched on it comes online, goes offline, and comes online again as far as the switch is concerned.  Therefore the "CamsUP" script runs twice, and the "CamsDOWN" script runs once.

Clearly just using the syslog lines isn't enough.  Adding a "cli wait" to either of these applets won't change anything because they will still run twice in the case of "CamsUP", and once in the case of "CamsDOWN".  If working properly "CamsUP" should only run once, and "CamsDOWN" shouldn't run at all when the controller is booting up.

Hope that makes sense.

[MHM Cisco World]

I will check solution 
MHM

[balaji.bandi]

Sure i agree what you mentioned in the post :

there is good discussion we had simular here - i offered some solution that seems to be reasonable working .

https://community.cisco.com/t5/network-management/eem-quot-bounce-quot-port-when-cannot-ping-internet/m-p/4992411#M155455

[Dan Frey · Accepted solution]

I believe having the wait command installed, then check the state of the interface to make sure it did not change is what is needed.  Gig1/0/25 is the "mock" interface with the WLC, and loopback0 is the camera port.   The policy below will work for the WLC port going up or down.  

event manager applet trackIntf
 event syslog pattern "LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/25, changed state to [a-z]+" maxrun 30
 action 010 cli command "enable"
 action 015 wait 15
 action 020 regexp "Line protocol on Interface (GigabitEthernet[0-9\/]+), changed state to ([a-z]+)" "$_syslog_msg" match intf initialState
 action 030 cli command "sh ip int brief $intf | inc Gig"
 action 040 regexp "GigabitEthernet[0-9\/]+ .* ([a-z]+)" "$_cli_result" match newState
 action 050 if $initialState eq $newState
 action 055 cli command "config term"
 action 056 cli command "interface range loopback0"
 action 060  if $newState eq down
 action 090   cli command "shutdown"
 action 100  else
 action 110   cli command "no shutdown"
 action 120  end
 action 130  syslog msg "Camera ports are $newState"
 action 140 end

 Your timestamps looks like the flapping happens in 8 seconds, so I put the wait at 15 seconds.   Flapping can happen in this window but the camera ports will not change state unless the state of the last syslog message matches the state when checked 15 seconds later.

C3750X-G(config-if)#no shut
C3750X-G(config-if)#shut
*May 31 02:14:50.278: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/25, changed state to up
C3750X-G(config-if)#
*May 31 02:15:00.436: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/25, changed state to down
C3750X-G(config-if)#no shut
C3750X-G(config-if)#
*May 31 02:15:14.789: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/25, changed state to up
C3750X-G(config-if)#
C3750X-G(config-if)#
C3750X-G(config-if)#
C3750X-G(config-if)#
*May 31 02:15:30.333: %HA_EM-6-LOG: trackIntf: Camera ports are up
*May 31 02:15:30.342: %SYS-5-CONFIG_I: Configured from console by vty1
*May 31 02:15:32.346: %LINK-3-UPDOWN: Interface Loopback0, changed state to up
*May 31 02:15:33.361: %LINEPROTO-5-UPDOWN: Line protocol on Interface Loopback0, changed state to up

[MHM Cisco World]

Sorry Mr @Dan Frey  
can He use syslog occur period in his case 
here he can add one EEM that detect event happened within specific time and it can trigger other EEM. 
can this way help him also 
because as I get from his reply the wait can delay action but if the link flapping it can led to run EEM multiple 
thanks a lot 
MHM

[DazOG]

Incredible, thanks!  That's great.  That looks much more elegant than what i came up with!

This is what I managed - untested - but the idea was that the "down" script would only be created when the "up" script had run, and that the "up" script would only run once in a 20 second period.  The "trigger delay 10" at the front was intended to stop the script creating the "down" applet too early (i.e. it should only be created and used after the controller is fully online).

event manager environment q "
event manager applet CamsUP
event syslog pattern "%LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to up" ratelimit 20
trigger delay 10
action 0010 syslog msg "--- Controller is UP, bringing up cameras ---"
action 0020 cli command "enable"
action 0030 cli command "conf t"
action 0040 cli command "int range gi2/0/28, gi2/0/30, gi2/0/32"
action 0050 cli command "no shut"
action 0060 cli command "exit"
action 0070 cli command "event manager applet CamsDOWN"
action 0080 cli command "description -- Applet to shut down cameras when controller goes offline"
action 0090 cli command "event syslog pattern $q %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to down $q"
action 0100 cli command "action 1.0 syslog msg $q --- Controller is DOWN, shutting down cameras --- $q"
action 0110 cli command "action 2.0 cli command $q enable $q"
action 0120 cli command "action 3.0 cli command $q conf t $q"
action 0130 cli command "action 4.0 cli command $q int range gi2/0/28, gi2/0/30, gi2/0/32 $q"
action 0140 cli command "action 5.0 cli command $q shut $q"
action 0150 cli command "action 6.0 cli command $q exit $q"
action 0160 cli command "action 7.0 cli command $q no event manager applet CamsDOWN $q"
action 0170 cli command "action 8.0 cli command $q end $q"
action 0180 cli command "syslog msg $q --- Camera turned OFF successfully --- $q"
action 0190 cli command "end"
action 0200 syslog msg "--- Cameras turned ON successfully ---"      

[DazOG]

I'll try your one tomorrow @Dan Frey - I really like how it's a "one size fits all" applet to handle both states.

[DazOG]

Tested my script this morning, seems to work correctly.  Log shows as follows:

Jan 16 10:05:46.524: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/3, changed state to up
Jan 16 10:05:47.530: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to up
Jan 16 10:05:49.191: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to down
Jan 16 10:05:50.206: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/3, changed state to down
Jan 16 10:05:54.786: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/3, changed state to up
Jan 16 10:05:55.793: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/0/3, changed state to up
Jan 16 10:05:57.571: %HA_EM-6-LOG: CamsUP: --- Controller is UP, bringing up cameras ---
Jan 16 10:05:58.605: %ILPOWER-7-DETECT: Interface Gi2/0/30: Power Device detected: IEEE PD (og-core-sw-2)
Jan 16 10:05:58.681: %ILPOWER-7-DETECT: Interface Gi2/0/32: Power Device detected: IEEE PD (og-core-sw-2)
Jan 16 10:05:59.752: %SYS-5-CONFIG_I: Configured from console by on vty1 (EEM:CamsUP)
Jan 16 10:05:59.794: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/28, changed state to down
Jan 16 10:05:59.819: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/30, changed state to down
Jan 16 10:05:59.827: %HA_EM-6-LOG: CamsUP: --- Cameras turned ON successfully ---
Jan 16 10:05:59.836: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/32, changed state to down
Jan 16 10:05:59.511: %ILPOWER-5-POWER_GRANTED: Interface Gi2/0/30: Power granted (og-core-sw-2)
Jan 16 10:05:59.528: %ILPOWER-5-POWER_GRANTED: Interface Gi2/0/32: Power granted (og-core-sw-2)
Jan 16 10:06:07.134: %LINK-3-UPDOWN: Interface GigabitEthernet2/0/30, changed state to up

The 10 second "trigger" delay between the initial line up and the execution of the applet, marked in red above worked and prevented the flap from interfering with it or triggering another instance (due to "ratelimit 20").  I can see that the "CamsDOWN" applet has been created and is ready to kick in when the cameras turn off now.

Despite this, I think I'll change it to @Dan Frey's as it is more elegant, not creating a temporary applet, etc.  Thanks again!