cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
4501
Views
0
Helpful
23
Replies

IP SLA/EEM running out of VTY lines and failing

Doug Boreham
Level 1
Level 1

I am using IP SLA to ping network devices to detect network failures from an AS5400XM voice gateway.  The AS5400XM platform is limited to 5 vty lines ( vty 0 4).  When simulating a simultaneous outage, there are not enough tty lines available to process my EEM events.

However, when simulating a simultaneous outage, we have a new issue – there are not enough lines available:
Feb  9 15:16:22.970 CST: %HA_EM-3-FMPD_CLI_CONNECT: Unable to establish CLI session: no tty lines available, minimum of 2 required by EEM
Feb  9 15:16:22.970 CST: %HA_EM-3-FMPD_ERROR: Error executing applet ReportIPSLAevent_1005065020_up statement 1.1
Feb  9 15:16:22.974 CST: %HA_EM-3-FMPD_CLI_CONNECT: Unable to establish CLI session: no tty lines available, minimum of 2 required by EEM
Feb  9 15:16:22.978 CST: %HA_EM-3-FMPD_ERROR: Error executing applet ReportIPSLAevent_1005081020_up statement 1.1
Feb  9 15:16:22.986 CST: %HA_EM-3-FMPD_CLI_CONNECT: Unable to establish CLI session: no tty lines available, minimum of 2 required by EEM
Feb  9 15:16:22.986 CST: %HA_EM-3-FMPD_ERROR: Error executing applet ReportIPSLAevent_100000226_up statement 1.1
Feb  9 15:16:22.994 CST: %HA_EM-3-FMPD_CLI_CONNECT: Unable to establish CLI session: no tty lines available, minimum of 2 required by EEM
Feb  9 15:16:22.994 CST: %HA_EM-3-FMPD_ERROR: Error executing applet ReportIPSLAevent_1001012021_up statement 1.1
Feb  9 15:16:23.006 CST: %HA_EM-3-FMPD_CLI_CONNECT: Unable to establish CLI session: no tty lines available, minimum of 2 required by EEM
Feb  9 15:16:23.006 CST: %HA_EM-3-FMPD_ERROR: Error executing applet ReportIPSLAevent_1061247018_up statement 1.1

How can I detect/wait until there are enough lines free before processing the EEM rules?

Regards,

-Doug

23 Replies 23

Try this version.

Joe,

So far, it looks like there are only two issues remaining:

Issue #1 - E-mail subject has destination listed as "unknown" versus the hostname

Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Subject: IP SLA alert - {router} connectivity to Unknown has been restored

Issue #2 - Source IP address issue (SMTP relay restricted to IP 10.5.32.90).  Traffic to the SMTP server needs to sourced from the Loopback0 address 10.5.32.90.  There are NAT rules in place to cover this, but it looks like the TCL script is bypassing the NAT:

#sh ip int brief | ex una
Interface                  IP-Address      OK? Method Status                Protocol
GigabitEthernet0/0         10.5.34.242     YES NVRAM  up                    up
GigabitEthernet0/1         10.5.34.250     YES NVRAM  up                    up
Loopback0                  10.5.32.90      YES NVRAM  up                    up
NVI0                       10.5.32.90      YES unset  up                    up

ip nat inside source list smtp-nat interface Loopback0 overload

sh ip access-lists smtp-nat
Extended IP access list smtp-nat
    10 permit ip host 10.5.34.242 host 10.0.10.10 (2 matches)
    20 permit ip host 10.5.34.250 host 10.0.10.10 (15 matches)

Feb 18 10:39:33.297 CST: FIBfwd-proc: sending link IP ip_pak_table 0 ip_nh_table 65535 if GigabitEthernet0/0 nh 10.5.34.241 uhp 1 deag 0 ttlexp 0 rec 0
Feb 18 10:39:33.297 CST: IP: s=10.5.34.242 (local), d=10.0.10.10 (GigabitEthernet0/0), len 58, sending
Feb 18 10:39:33.297 CST:     TCP src=26095, dst=25, seq=3453704840, ack=2112864439, win=3890 ACK
Feb 18 10:39:33.297 CST: IP: s=10.5.34.242 (local), d=10.0.10.10 (GigabitEthernet0/0), len 58, output feature
Feb 18 10:39:33.297 CST:     TCP src=26095, dst=25, seq=3453704840, ack=2112864439, win=3890 ACK, CCE Output Classification(5), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:33.297 CST: IP: s=10.5.32.90 (local), d=10.0.10.10 (GigabitEthernet0/0), len 58, output feature
Feb 18 10:39:33.297 CST:     TCP src=26095, dst=25, seq=3453704840, ack=2112864439, win=3890 ACK, Post-routing NAT Outside(17), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:33.297 CST: IP: s=10.5.32.90 (local), d=10.0.10.10 (GigabitEthernet0/0), len 58, output feature
Feb 18 10:39:33.297 CST:     TCP src=26095, dst=25, seq=3453704840, ack=2112864439, win=3890 ACK, Stateful Inspection(20), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:33.297 CST: IP: s=10.5.32.90 (local), d=10.0.10.10 (GigabitEthernet0/0), len 58, sending full packet
Feb 18 10:39:33.297 CST:     TCP src=26095, dst=25, seq=3453704840, ack=2112864439, win=3890 ACK
Feb 18 10:39:33.297 CST: [fh_smtp_debug_cmd]
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : From: {router}@mydomain.com
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : To: recipient@mydomain.com
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Cc:
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Subject: IP SLA alert - {router} connectivity to Unknown has been restored
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : IPSLAs Latest Operation Statistics
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : IPSLA operation id: 100000226
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Type of operation: icmp-echo
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write :    Latest RTT: 36 milliseconds
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Latest operation start time: 10:39:29.377 CST Thu Feb 18 2010
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Latest operation return code: OK
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Number of successes: 21
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Number of failures: 13
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Operation time to live: Forever
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : {router}
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write :
Feb 18 10:39:33.297 CST: [fh_smtp_debug_cmd]
Feb 18 10:39:33.297 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : .
Feb 18 10:39:33.529 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:33.529 CST:     TCP src=25, dst=26095, seq=2112864439, ack=3453704858, win=65374 ACK, Stateful Inspection(4), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:33.529 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:33.529 CST:     TCP src=25, dst=26095, seq=2112864439, ack=3453704858, win=65374 ACK, Virtual Fragment Reassembly(21), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:33.529 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:33.529 CST:     TCP src=25, dst=26095, seq=2112864439, ack=3453704858, win=65374 ACK, Virtual Fragment Reassembly After IPSec Decryption(32), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:33.529 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:33.529 CST:     TCP src=25, dst=26095, seq=2112864439, ack=3453704858, win=65374 ACK, NAT Outside(53), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:33.529 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:33.529 CST:     TCP src=25, dst=26095, seq=2112864439, ack=3453704858, win=65374 ACK, MCI Check(64), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:33.529 CST: FIBipv4-packet-proc: route packet from GigabitEthernet0/1 src 10.0.10.10 dst 10.5.34.242
Feb 18 10:39:33.529 CST: FIBfwd-proc: Default:10.5.34.242/32 receive entry

Error:

Feb 18 10:39:33.529 CST: FIBipv4-packet-proc: packet routing failed
Feb 18 10:39:33.529 CST: IP: tableid=0, s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), routed via RIB
Feb 18 10:39:33.529 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), len 40, output feature
Feb 18 10:39:33.529 CST:     TCP src=25, dst=26095, seq=2112864439, ack=3453704858, win=65374 ACK ACK
Feb 18 10:39:33.953 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, stop process pak for forus packet
Feb 18 10:39:33.953 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK
Feb 18 10:39:34.245 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 88, input feature
Feb 18 10:39:34.245 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH, Stateful Inspection(4), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.245 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 88, input feature
Feb 18 10:39:34.245 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH, Virtual Fragment Reassembly(21), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 88, input feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH, Virtual Fragment Reassembly After IPSec Decryption(32), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 88, input feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH, NAT Outside(53), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 88, input feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH, MCI Check(64), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: FIBipv4-packet-proc: route packet from GigabitEthernet0/1 src 10.0.10.10 dst 10.5.34.242
Feb 18 10:39:34.249 CST: FIBfwd-proc: Default:10.5.34.242/32 receive entry

Error:

Feb 18 10:39:34.249 CST: FIBipv4-packet-proc: packet routing failed
Feb 18 10:39:34.249 CST: IP: tableid=0, s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), routed via RIB
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), len 88, output feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH, CCE Output Classification(5), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), len 88, output feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH, Post-routing NAT Outside(17), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), len 88, output feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH, Stateful Inspection(20), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 88, rcvd 4
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 88, stop process pak for forus packet
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864535, ack=3453704892, win=65340 ACK PSH
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN, Stateful Inspection(4), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN, Virtual Fragment Reassembly(21), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN, Virtual Fragment Reassembly After IPSec Decryption(32), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN, NAT Outside(53), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, input feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN, MCI Check(64), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: FIBipv4-packet-proc: route packet from GigabitEthernet0/1 src 10.0.10.10 dst 10.5.34.242
Feb 18 10:39:34.249 CST: FIBfwd-proc: Default:10.5.34.242/32 receive entry

Error:

Feb 18 10:39:34.249 CST: FIBipv4-packet-proc: packet routing failed
Feb 18 10:39:34.249 CST: IP: tableid=0, s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), routed via RIB
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), len 40, output feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN, CCE Output Classification(5), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), len 40, output feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN, Post-routing NAT Outside(17), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242 (GigabitEthernet0/0), len 40, output feature
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN, Stateful Inspection(20), rtype 1, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, rcvd 4
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN
Feb 18 10:39:34.249 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, stop process pak for forus packet
Feb 18 10:39:34.249 CST:     TCP src=25, dst=26095, seq=2112864583, ack=3453704892, win=65340 ACK FIN
Feb 18 10:39:34.249 CST: IP: s=10.5.34.242 (local), d=10.0.10.10, len 40, local feature
Feb 18 10:39:34.249 CST:     TCP src=26095, dst=25, seq=3453704892, ack=2112864584, win=3746 ACK, NAT(2), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
Feb 18 10:39:34.249 CST: FIBipv4-packet-proc: route packet from (local) src 10.5.34.242 dst 10.0.10.10
Feb 18 10:39:34.249 CST: FIBfwd-proc: Default:10.0.0.0/20 proces level forwarding
Feb 18 10:39:34.249 CST: FIBfwd-proc: depth 0 first_idx 0 paths 2 long 0(0)
Feb 18 10:39:34.249 CST: FIBfwd-proc: try path 0 (of 2) v4-anh-10.5.34.241-Gi0/0 first short ext 0(-1)
Feb 18 10:39:34.249 CST: FIBfwd-proc: v4-anh-10.5.34.241-Gi0/0 valid
Feb 18 10:39:34.249 CST: FIBfwd-proc: ip_pak_table 0 ip_nh_table 65535 if GigabitEthernet0/0 nh 10.5.34.241 deag 0 via fib 0 path type attached nexthop
Feb 18 10:39:34.249 CST: FIBfwd-proc: packet routed to GigabitEthernet0/0 10.5.34.241(0)
Feb 18 10:39:34.249 CST: FIBipv4-packet-proc: packet routing succeeded ACK
Feb 18 10:39:34.405 CST: IP: s=10.0.10.10 (GigabitEthernet0/1), d=10.5.34.242, len 40, stop process pak for forus packet
Feb 18 10:39:34.405 CST:     TCP src=25, dst=26095, seq=2112864584, ack=3453704893, win=65340 ACK

Regards,

-Doug

P.S.  Can you recommend any documents or books to learn Tcl?

1. Post the output of "show ip sla conf" so I can confirm the regular expression I wrote is correct.  The code works on my test router.

2. This version should fix the source interface problem.  Just set the environment variable _email_src_intf:

event manager environment _email_src_intf Loopback0

Cisco Press is currently working on a book on Tcl scripting in IOS.  I'm reviewing it, and it should be a good reference for our customers.  It should be out by the end of the calendar year.

I think I found the problem with the traget address regexp.  This version should have all the required fixes.

output from "show ip sla conf":

IP SLAs Infrastructure Engine-II
Entry number: 100000226
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.0.0.226
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0xB8
Vrf Name:
Request size (ARR data portion): 200
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Start Time already passed
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): Forever
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): Active
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 3
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 1
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:
   Aggregation Interval:900 Buckets:100

Entry number: 100500226
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.5.0.226
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0xB8
Vrf Name:
Request size (ARR data portion): 200
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Start Time already passed
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): Forever
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): Active
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 3
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 1
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:
   Aggregation Interval:900 Buckets:100

Entry number: 100564197
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.5.64.197
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0xB8
Vrf Name:
Request size (ARR data portion): 200
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Start Time already passed
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): Forever
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): Active
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 3
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 1
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:
   Aggregation Interval:900 Buckets:100

Entry number: 1001011011
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.0.11.11
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0xB8
Vrf Name:
Request size (ARR data portion): 200
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Start Time already passed
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): Forever
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): Active
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 3
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 1
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:
   Aggregation Interval:900 Buckets:100

Entry number: 1001012021
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.0.12.21
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0xB8
Vrf Name:
Request size (ARR data portion): 200
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Start Time already passed
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): Forever
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): Active
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 3
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 1
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:
   Aggregation Interval:900 Buckets:100

Entry number: 1005019195
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.5.19.195
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0x0
Vrf Name:
Request size (ARR data portion): 28
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Pending trigger
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): 3600
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): notInService
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 2
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 0
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:

Entry number: 1005065020
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.5.65.20
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0xB8
Vrf Name:
Request size (ARR data portion): 200
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Start Time already passed
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): Forever
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): Active
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 3
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 1
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:
   Aggregation Interval:900 Buckets:100

Entry number: 1005081020
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.5.81.20
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0xB8
Vrf Name:
Request size (ARR data portion): 200
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Start Time already passed
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): Forever
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): Active
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 3
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 1
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:
   Aggregation Interval:900 Buckets:100

Entry number: 1061247018
Owner:
Tag:
Type of operation to perform: icmp-echo
Target address/Source address: 0.0.0.0/10.61.247.18
Operation timeout (milliseconds): 5000
Type Of Service parameters: 0xB8
Vrf Name:
Request size (ARR data portion): 200
Verify data: No
Schedule:
   Operation frequency (seconds): 60  (not considered if randomly scheduled)
   Next Scheduled Start Time: Start Time already passed
   Group Scheduled : FALSE
   Randomly Scheduled : FALSE
   Life (seconds): Forever
   Entry Ageout (seconds): never
   Recurring (Starting Everyday): FALSE
   Status of entry (SNMP RowStatus): Active
Threshold (milliseconds): 5000 (not considered if react RTT is configured)
Distribution Statistics:
   Number of statistic hours kept: 3
   Number of statistic distribution buckets kept: 1
   Statistic distribution interval (milliseconds): 20
History Statistics:
   Number of history Lives kept: 1
   Number of history Buckets kept: 15
   History Filter Type: None
Enhanced History:
   Aggregation Interval:900 Buckets:100

Since it is only February, if you can share any other Tcl references that would be greatly appreciated.

Regards,

-Doug

Ugh, it looks like your device is being bit by CSCsy37122.  I'll have to hack around that.  Try the attached version.

As for good Tcl books, I like Practical Programming in Tcl and Tk (4th Edition) (ISBN-13 978-0130385604).

Joe,

From what I can see, the message should have been delivered, but we did not receive it.  Also, the subject is still not showing the hostname.

Can you take a look at the debugs here and the mail server(s) to see if you can tell what the issue might be?

Here is a debug of the communications between {router} (IP address 10.5.32.90) and the SMTP relay:

Feb 18 15:39:30.156 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_connect : attempt 1

Feb 18 15:39:30.192 CST: [fh_intf_get_ip_cmd]

Feb 18 15:39:30.372 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:30.372 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_read  : 220 SMTPSERVER.mydomain.com Microsoft ESMTP MAIL Service ready at Thu, 18 Feb 2010 16:39:26 -0500

Feb 18 15:39:30.372 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:30.372 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : HELO {router}.mydomain.com

Feb 18 15:39:30.904 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:30.904 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_read  : 250 SMTPSERVER.mydomain.com Hello [10.5.32.90]

Feb 18 15:39:30.904 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:30.904 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : MAIL FROM:<{router}@mydomain.com>

Feb 18 15:39:31.432 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:31.432 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_read  : 250 2.1.0 Sender OK

Feb 18 15:39:31.432 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:31.432 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : RCPT TO:<recipient@mydomain.com>

Feb 18 15:39:31.952 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:31.952 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_read  : 250 2.1.5 Recipient OK

Feb 18 15:39:31.952 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:31.952 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : DATA

Feb 18 15:39:32.484 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:32.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_read  : 354 Start mail input; end with .

Feb 18 15:39:32.484 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:32.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Date: 18 Feb 2010 15:39:32 CST

Feb 18 15:39:32.484 CST: [fh_fts_get_stamp_cmd]

Feb 18 15:39:32.484 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:32.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Message-ID: <20100218153932.1872627720@{router}.mydomain.com>

Feb 18 15:39:33.484 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : From: {router}@mydomain.com

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : To: recipient@mydomain.com

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Cc:

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Subject: IP SLA alert - {router} connectivity to 0.0.0.0 has been restored

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : IPSLAs Latest Operation Statistics

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : IPSLA operation id: 100000226

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Type of operation: icmp-echo

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write :    Latest RTT: 40 milliseconds

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Latest operation start time: 15:39:29.532 CST Thu Feb 18 2010

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Latest operation return code: OK

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Number of successes: 3

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Number of failures: 31

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : Operation time to live: Forever

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : {router}>

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write :

Feb 18 15:39:33.484 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:33.484 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : .

Feb 18 15:39:33.884 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:33.884 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_read  : 250 2.6.0 <20100218153932.1872627720@{router}.mydomain.com> Queued mail for delivery

Feb 18 15:39:33.884 CST: [fh_smtp_debug_cmd]

Feb 18 15:39:33.884 CST: %HA_EM-6-LOG: sl_ip_sla_report.tcl : DEBUG(smtp_lib) : smtp_write : QUIT

Feb 18 15:39:34.320 CST: EM: No consumer registered for any event type

Regards,

-Doug

Yeah, this debug output looks good.  The SMTP server accepted the message, and it should get delivered to receipient@mydomain.com.  If not, you would need to debug things from the SMTP side.

As for the subject, it looks like you may not be using the very latest version of the script I sent out.  I attempted to workaround the bug you're seeing in that version.  You should see lines in the script like:

if { $target_ip == "0.0.0.0" } {

   set traget_ip $source_ip

}

Doug Boreham
Level 1
Level 1

Cisco IOS Software, 5400 Software (C5400-IK9S-M), Version 12.4(24)T2, RELEASE SOFTWARE (fc2)

Technical Support: http://www.cisco.com/techsupport

Copyright (c) 1986-2009 by Cisco Systems, Inc.

Compiled Mon 19-Oct-09 22:25 by prod_rel_team

ROM: System Bootstrap, Version 12.4(22r)T, RELEASE SOFTWARE (fc1)

System image file is "flash:c5400-ik9s-mz.124-24.T2.bin"

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: