Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
Announcements

Welcome to Cisco Support Community. We would love to have your feedback.

For an introduction to the new site, click here. And see here for current known issues.

New Member

Problem in EEM Config

Dear All,

I have Written the EEM config , which tracks the serial interface for line protocol for UP & DOWN state.

Purpose for writting is to remove the access-list automatocally; configured under interface fastethernet 0/0.400 when the link goes down

It works perfectly fine when the link goes down ( tracking with serial interface line-protocol). But when the link comes up its not working.

track 1 interface Serial0/1/0 line-protocol

event manager session cli username "admin"

event manager applet NAC-REMOVED

event track 1 state down maxrun 6000

action 1.1 cli command "enable"

action 1.2 cli command "config t"

action 1.3 cli command "interface FastEthernet0/0.400"

action 1.4 cli command "no ip access-group NAC_ACL in"

event manager applet NAC-APPLIED

event track 1 state up maxrun 6000

action 1.1 cli command "enable"

action 1.2 cli command "config t"

action 1.3 cli command "interface FastEthernet0/0.400"

action 1.4 cli command "ip access-group NAC_ACL in"

!

end

Below is the O/P of Debug Event Manager when the link comes up

=========================================================================================================

Mar 20 13:07:16.900: eem_no_scan flag set, skipping scan of command_string=check_eem_cli_policy_handler

Mar 20 13:07:17.952: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial0/1/0, changed state to up

JAU-543268000-BAJRAN(config-if)#

Mar 20 13:07:17.952: fh_fd_syslog_event_match: num_matches = 0

Mar 20 13:07:17.952: fh_fd_data_syslog: num_matches = 0

JAU-543268000-BAJRAN(config-if)#

Mar 20 13:07:19.827: %BGP-5-ADJCHANGE: neighbor 10.90.4.2 Up

JAU-543268000-BAJRAN(config-if)#

Mar 20 13:07:19.827: fh_fd_syslog_event_match: num_matches = 0

Mar 20 13:07:19.827: fh_fd_data_syslog: num_matches = 0

JAU-543268000-BAJRAN(config-if)#

Mar 20 13:07:21.723: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT :

Mar 20 13:07:21.723: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : Enter configuration commands, one per line.  End with CNTL/Z.

Mar 20 13:07:21.723: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : JAU-543268000-BAJRAN(config)#

Mar 20 13:07:21.723: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : CTL : cli_close called.

Mar 20 13:07:21.723: fh_server: fh_io_msg: received msg FH_MSG_CALLBACK_DONE from client 17 pclient 1

Mar 20 13:07:21.723: fh_io_msg: EEM callback policy NAC-APPLIED has ended with abnormal exit status of 0xFFFFFFFF

Mar 20 13:07:21.723: EEM policy NAC-APPLIED has exceeded it's elapsed time limit of 6000.0 seconds

Mar 20 13:07:21.723: fh_schedule_callback: fh_schedule_callback: cc=646CCB90 prev_epc=639BFA10; epc=0

Mar 20 13:07:21.723: fh_server: fh_io_msg: received msg FH_MSG_API_CLOSE from client 17 pclient 1

Mar 20 13:07:21.723: fh_io_msg: received FH_MSG_API_CLOSE client=17

======================================================================================================

Attached is the Debug O/P, kindly Guide me why is it not working and how to make it work

Regards,.

Ranjit

4 REPLIES
Cisco Employee

Problem in EEM Config

Hello,

Thats quite strange. EEM is closed because it thinks that it exceeded elapsed time limit:

Mar 20 13:07:21.723: EEM policy NAC-APPLIED has exceeded it's elapsed time limit of 6000.0 seconds

However only few miliseconds passed since it started. Can you check if you get any High CPU when this script is running

- show proc cpu sort

- show proc cpu hist

Can you also try changin maxrun value to some other - possibly even default (20 sec) or 100 and see if that works or gives same debug outputs.

BTW what is the platform and OS?

Nik

New Member

Problem in EEM Config

D

ear Nikolay,

Thanks for your reply.

Platform is 1841 & IOS we are using is c1841-advsecurityk9-mz.124-11.T4.bin.

I will check the

- show proc cpu sort

- show proc cpu hist

and update

Regards,

Ranjit

New Member

Problem in EEM Config

Dear Nikolay

Its Certainly strange the same config is working in c1841-advsecurityk9-mz.150-1.M3.bin IOS.

Below are the logs

====================================================================================

JAU-536369000-SINGRA(config-if)#

.Mar 21 12:54:36.291: %TRACKING-5-STATE: 1 ip sla 1 reachability Down->Up

.Mar 21 12:54:36.291: fh_track_object_changed: Track notification 1 state up

.Mar 21 12:54:36.291: fh_fd_track_event_match: track ED pubinfo enqueue rc = 0

.Mar 21 12:54:36.291: fh_track_object_changed: Track notification 1 state up

.Mar 21 12:54:36.291: fh_fd_syslog_event_match: num_matches = 0

.Mar 21 12:54:36.291: fh_fd_data_syslog: num_matches = 0

.Mar 21 12:54:36.291: fh_send_server_sig_hndlr: received a pulse from track on n ode0/0 with fdid: 4

.Mar 21 12:54:36.291: fh_send_track_fd_msg: msg_type=64

.Mar 21 12:54:36.291: fh_send_track_fd_msg: sval=0

.Mar 21 12:54:36.291: fh_send_server_sig_hndlr: received FH_MSG_EVENT_PUBLISH

.Mar 21 12:54:36.291: EEM: server processes multi events: timewin=1, sync_flag=0 , ec_index=0, cmp_occ=1

.Mar 21 12:54:36.291: EEM: ctx=5:(5,1,1)

.Mar 21 12:54:36.291: EEM: server processes multi events: corr_res=1, cur_tcnt=1 , cmp_tcnt=1

.Mar 21 12:54:36.291: fh_schedule_callback: fh_schedule_callback: cc=65DF4B0C pr ev_epc=0; epc=66947FC0

.Mar 21 12:54:36.291: EEM server schedules callbacks: policy_type: 2

.Mar 21 12:54:36.291: EEM server schedules one event: policy_type=applet epc=669 47FC0.

.Mar 21 12:54:36.291: fh_schedule_a_callback: EEM callback policy NAC-APPLIED ha s been scheduled to run. fdid: 4 sn: 1 jobid: 4

.Mar 21 12:54:36.295: fh_io_msg: received FH_MSG_API_INIT; jobid=15, processid=2 78, client=5, job name=EEM Callback Thread

.Mar 21 12:54:36.295: fh_server: fh_io_msg: received msg FH_MSG_EVENT_REQINFO_MU LTI from client 5 pclient 1

.Mar 21 12:54:36.295: Registering tag: id: 1

.Mar 21 12:54:36.295: Pushing tag on to stack

.Mar 21 12:54:36.295: open tag is

.Mar 21 12:54:36.295: Pushing tag on to stack

.Mar 21 12:54:36.295: open tag is

.Mar 21 12:54:36.295: Pushing tag on to stack

.Mar 21 12:54:36.295: open tag is

.Mar 21 12:54:36.295: Name-Value Pair: Name=(pdir) Value=(_event_type)

.Mar 21 12:54:36.295: Name-Value Pair: Name=(tcl) Value=(event_type)

.Mar 21 12:54:36.295: Pushing tag on to stack

.Mar 21 12:54:36.295: open tag is

.Mar 21 12:54:36.295: Popping tag off stack

.Mar 21 12:54:36.295: close tag is

.Mar 21 12:54:36.295: Popping tag off stack

.Mar 21 12:54:36.295: close tag is

.Mar 21 12:54:36.295: Pushing tag on to stack

.Mar 21 12:54:36.295: open tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Name-Value Pair: Name=(pdir) Value=(_event_type_string)

.Mar 21 12:54:36.299: Name-Value Pair: Name=(tcl) Value=(event_type_string)

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Popping tag

JAU-536369000-SINGRAMAU#vent_name> off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Name-Value Pair: Name=(pdir) Value=(_event_severity)

.Mar 21 12:54:36.299: Name-Value Pair: Name=(tcl) Value=(event_severity)

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Name-Value Pair: Name=(pdir) Value=(_track_number)

.Mar 21 12:54:36.299: Name-Value Pair: Name=(tcl) Value=(track_number)

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Name-Value Pair: Name=(pdir) Value=(_track_state)

.Mar 21 12:54:36.299: Name-Value Pair: Name=(tcl) Value=(track_state)

.Mar 21 12:54:36.299: Pushing tag on to stack

.Mar 21 12:54:36.299: open tag is

.Mar 21 12:54:36.299: Popping tag off stack

.Mar 21 12:54:36.299: close tag is

.Mar 21 12:54:36.303: Popping tag off stack

.Mar 21 12:54:36.303: close tag is

.Mar 21 12:54:36.303: Popping tag off stack

.Mar 21 12:54:36.303: close tag is

.Mar 21 12:54:36.303: Popping tag off stack

.Mar 21 12:54:36.303: close tag is

.Mar 21 12:54:36.303: EEM: policy_dir xml builtin: name:_event_type value:211

.Mar 21 12:54:36.303: EEM: policy_dir xml builtin: name:_event_type_string value :track

.Mar 21 12:54:36.303: EEM: policy_dir xml builtin: name:_event_severity value:se verity-normal

.Mar 21 12:54:36.303: EEM: policy_dir xml builtin: name:_track_number value:1

.Mar 21 12:54:36.303: EEM: policy_dir xml builtin: name:_track_state value:up

.Mar 21 12:54:36.303: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : CTL : cli_o pen called.

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : CC

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT :

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT :

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : +- ---------------------------------------------------------------------+

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | This is an UBI bank computer system. This system is for the use of |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | authorized users only. Individuals using this system without |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | authority, or inexcess of their authority,are subject to having |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | all of their activities on this system monitored and recorded by |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | system personnel. |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | In the course of monitoring individuals improperly using this |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | system, or in the course of system maintenance, the activities |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | of authorized users may also be monitored. |

.Mar 21 12:54:36.323: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | |

.Mar 21 12:54:36.327: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | Anyone using this system expressly consents to such monitoring |

.Mar 21 12:54:36.327: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | and is advised that if such monitoring reveals possible |

.Mar 21 12:54:36.327: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | evidence of criminal activity, system personnel may provide the |

.Mar 21 12:54:36.327: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | evidence of such monitoring to law enforcement officials. |

.Mar 21 12:54:36.327: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : | |

.Mar 21 12:54:36.327: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : +----------------------------------------------------------------------+

.Mar 21 12:54:36.327: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : CTL : 20+ lines read from cli, debug output truncated

.Mar 21 12:54:36.327: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : IN : JAU-536369000-SINGRAMAU#enable

.Mar 21 12:54:36.327: cli_history_entry_add: free_hist_list size=0, hist_list size=7

.Mar 21 12:54:36.327: eem_no_scan flag set, skipping scan of command_string=check_eem_cli_policy_handler

.Mar 21 12:54:36.343: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : JAU-536369000-SINGRAMAU#

.Mar 21 12:54:36.343: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : IN : JAU-536369000-SINGRAMAU#config t

.Mar 21 12:54:36.611: cli_history_entry_add: free_hist_list size=0, hist_list size=7

.Mar 21 12:54:36.611: eem_no_scan flag set, skipping scan of command_string=check_eem_cli_policy_handler

.Mar 21 12:54:36.663: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : Enter configuration commands, one per line. End with CNTL/Z.

.Mar 21 12:54:36.663: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : JAU-536369000-SINGRA(config)#

.Mar 21 12:54:36.663: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : IN : JAU-536369000-SINGRA(config)#interface FastEthernet0/0.400

.Mar 21 12:54:36.931: cli_history_entry_add: free_hist_list size=0, hist_list size=7

.Mar 21 12:54:36.931: eem_no_scan flag set, skipping scan of command_string=check_eem_cli_policy_handler

.Mar 21 12:54:36.979: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : JAU-536369000-SINGRA(config-subif)#

.Mar 21 12:54:36.979: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : IN : JAU-536369000-SINGRA(config-subif)#ip access-group NAC_ACL in

.Mar 21 12:54:37.255: cli_history_entry_add: free_hist_list size=0, hist_list size=7

.Mar 21 12:54:37.255: eem_no_scan flag set, skipping scan of command_string=check_eem_cli_policy_handler

.Mar 21 12:54:37.295: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : OUT : JAU-536369000-SINGRA(config-subif)#

.Mar 21 12:54:37.295: %HA_EM-6-LOG: NAC-APPLIED : DEBUG(cli_lib) : : CTL : cli_close called.

.Mar 21 12:54:37.299: fh_server: fh_io_msg: received msg FH_MSG_CALLBACK_DONE from client 5 pclient 1

.Mar 21 12:54:37.299: fh_io_msg: EEM callback policy NAC-APPLIED has ended with normal exit status of 0x0

.Mar 21 12:54:37.299: EEM: server decrements in use thread: jobid=4 rule id=2 in use thread=0.

.Mar 21 12:54:37.299: fh_schedule_callback: fh_schedule_callback: cc=65DF4B0C prev_epc=66947FC0; epc=0

.Mar 21 12:54:37.299: EEM server schedules callbacks: policy_type: 2

.Mar 21 12:54:37.299: fh_schedule_policy: prev_epc=0x0; epc=0x0

.Mar 21 12:54:37.299: EEM server schedules scripts

.Mar 21 12:54:37.299: fh_server: fh_io_msg: received msg FH_MSG_API_CLOSE from client 5 pclient 1

.Mar 21 12:54:37.299: fh_io_msg: received FH_MSG_API_CLOSE client=5

.Mar 21 12:54:37.299: %SYS-5-CONFIG_I: Configured from console by vty2

.Mar 21 12:54:37.299: fh_fd_config_event_match: num_matches = 0

.Mar 21 12:54:37.299: fh_fd_config_event_notify:

.Mar 21 12:54:37.299: fh_fd_syslog_event_match: num_matches = 0

.Mar 21 12:54:37.303: fh_fd_data_syslog: num_matches = 0

.Mar 21 12:54:43.435: %SYS-5-CONFIG_I: Configured from console by ranjit on vty1 (10.31.0.20)

.Mar 21 12:54:43.435: fh_fd_syslog_event_match: num_matches = 0

.Mar 21 12:54:43.435: fh_fd_data_syslog: num_matches = 0

.Mar 21 12:54:52.278: %CRYPTO-4-RECVD_PKT_NOT_IPSEC: Rec'd packet not an IPSEC packet. (ip) vrf/dest_addr= /10.40.8.55, src_addr= 172.31.12.121, prot= 6

.Mar 21 12:54:52.282: fh_fd_syslog_event_match: num_matches = 0

.Mar 21 12:54:52.282: fh_fd_data_syslog: num_matches = 0

.Mar 21 12:55:00.002: fh_fd_timer_process_async

.Mar 21 12:55:00.002: cron_tick: num_matches 0

.Mar 21 12:55:09.410: %SYS-5-CONFIG_I: Configured from console by ranjit on vty0 (10.31.0.20)

.Mar 21 12:55:09.410: %IP_SNMP-4-NOTRAPIP: SNMP trap source FastEthernet0/0 has no ip address

.Mar 21 12:55:09.414: fh_fd_syslog_event_match: num_matches = 0

.Mar 21 12:55:09.414: fh_fd_data_syslog: num_matches = 0

.Mar 21 12:55:09.414: fh_fd_syslog_event_match: num_matches = 0

.Mar 21 12:55:09.414: fh_fd_data_syslog: num_matches = 0

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#

JAU-536369000-SINGRAMAU#show run int fas

JAU-536369000-SINGRAMAU#show run int fastEthernet 0/0.400

Building configuration...

Current configuration : 178 bytes

!

interface FastEthernet0/0.400

description ***Connected to AUTH VLAN***

encapsulation dot1Q 400

ip unnumbered Loopback255

ip access-group NAC_ACL in <-------------------- Access list applied again after link has come up

no ip route-cache

end

=================================================================================

Regards,

Ranjit

Cisco Employee

Problem in EEM Config

Yeap indeed.

From the quick search I did not find any DDTS - so it may be worth opening TAC case to check it in more details. Also as I said before you can try playing with the maxrun timer removing it or changing to other values and see if that works or still fail just to find a workaround.

Nik

515
Views
0
Helpful
4
Replies
CreatePlease login to create content