EEM Scripts not capturing logs to flash

[Pradeep H A]

Hello all,

I have used the below EEM script on a Cisco 3750G running IOS Version 15.0(2)SE to capture the logs when CPU spikes that help in the investigation of the reason for intermittent CPU spikes. But I saw that the logs are not being captured into a file.

conf t
process cpu threshold type total rising 85 interval 30 falling 70 interval 30
event manager session cli username "user"
event manager applet cpu_stats-user
event snmp oid 1.3.6.1.4.1.9.9.109.1.1.1.1.3.1 get-type exact entry-op gt entry-val 80 exit-op lt exit-val 70 poll-interval 5
action 1.1 syslog msg "------HIGH CPU DETECTED----, CPU: $_snmp_oid_val %"
action 1.2 cli command "enable"
action 1.3 cli command "show clock | append flash:cpu_stats-user.txt"
action 1.4 cli command "show proc cpu sort | append flash:cpu_stats-user.txt"
action 1.5 cli command "show interfaces | append flash:cpu_stats-user.txt"
action 1.7 cli command "sho spann detail | append flash:cpu_stats-user.txt"
action 1.8 cli command "show proc cpu sort | append flash:cpu_stats-user.txt"
action 1.9 cli command "sho log | append flash:cpu_stats-user.txt"
action 1.10 cli command "show ip traffic | append flash:cpu_stats-user.txt"
action 1.11 syslog msg "Finished gathering information to flash:cpu_stats-user.txt..."
action 1.12 cli command "exit"
end
exit

The above commands didnt automatically create a file in the flash. So I created one with the command "show version | redirect flash:cpu_stats-user.txt". Still when the CPU spikes I see logs like this in show log but nothing is being appended to the file in the flash.

061019: Jun 18 00:36:37.061: %HA_EM-6-LOG: cpu_stats-user: ------HIGH CPU DETECTED----, CPU: 98 %
061020: Jun 18 00:36:37.204: %HA_EM-6-LOG: cpu_stats-user: Finished gathering information to flash:cpu_stats-user.txt...
061021: Jun 18 01:36:43.256: %HA_EM-6-LOG: cpu_stats-user: ------HIGH CPU DETECTED----, CPU: 99 %
061022: Jun 18 01:36:43.407: %HA_EM-6-LOG: cpu_stats-user: Finished gathering information to flash:cpu_stats-user.txt...
061023: Jun 18 02:25:23.413: %HA_EM-6-LOG: cpu_stats-user: ------HIGH CPU DETECTED----, CPU: 90 %
061024: Jun 18 02:25:23.572: %HA_EM-6-LOG: cpu_stats-user: Finished gathering information to flash:cpu_stats-user.txt...
061025: Jun 18 03:47:21.998: %HA_EM-6-LOG: cpu_stats-user: ------HIGH CPU DETECTED----, CPU: 99 %
061026: Jun 18 03:47:22.141: %HA_EM-6-LOG: cpu_stats-user: Finished gathering information to flash:cpu_stats-user.txt...
061027: Jun 18 23:37:50.956: %HA_EM-6-LOG: cpu_stats-user: ------HIGH CPU DETECTED----, CPU: 88 %
061028: Jun 18 23:37:51.015: %HA_EM-6-LOG: cpu_stats-user: Finished gathering information to flash:cpu_stats-user.txt...

Can any one help me out?

Thanks a lot in advance!

[Francesco Molino · Accepted solution]

Hi

append is not working on certain file system but, as far as I remember, it should work.

Could you directly on enable mode: sh run | append flash:/test.txt ?

If this isn't working, test with the command: sh run | redirect flash?test.txt

Let me know.

Thanks

PS: Please don't forget to rate and mark as correct answer if this solved your issue

[Pradeep H A]

Hi supportlan,

Yes, The append operation is not supported on this switch flash.

C3750#sh ver | append flash:pradeep.txt
% Appending is not supported in this file system

I re-configured the action commands in the EEM script to use "redirect" instead of "append" as shown below

 action 1.1  syslog msg "------HIGH CPU DETECTED----, CPU: $_snmp_oid_val %"
 action 1.2  cli command "enable"
 action 1.3  cli command "show clock | redirect flash:user-clock.txt"
 action 1.4  cli command "show proc cpu sort | redirect flash:user-cpu.txt"
 action 1.5  cli command "show interfaces | redirect flash:user-int.txt"
 action 1.7  cli command "sho spann detail | redirect flash:user-STP.txt"
 action 1.9  cli command "sho log | redirect flash:user-LOG.txt"
 action 1.10 cli command "show ip traffic | redirect flash:user-IP.txt"
 action 1.11 syslog msg "Finished gathering information to flash:cpu_stats-user.txt..."
 action 1.12 cli command "exit"

but the problem here is above script would capture only the first occurence output as the CLI doesnt get the permission to overwrite the existing file on the second occurence.

One more problem is with the above script i am seeing only user-clock.txt & user-cpu.txt files are getting created with output in the flash. The rest of the command output files are not there in flash. Not sure why?

C3750#sh flash

Directory of flash:/

    2  -rwx        2296   Mar 1 1993 00:03:01 +00:00  vlan.dat
    3  drwx         512   Mar 1 1993 00:35:42 +00:00  c3750-ipservicesk9-mz.122-55.SE9
  510  -rwx        1940  Jun 29 2016 02:21:20 +00:00  private-config.text
  513  -rwx          33  Jun 25 2016 09:14:15 +00:00  user-clock.txt
  512  -rwx       18456  Jun 29 2016 02:21:20 +00:00  multiple-fs
  514  -rwx       24287  Jun 25 2016 09:14:15 +00:00  user-cpu.txt
  515  -rwx       75406  Jun 29 2016 02:21:16 +00:00  config.text

27998208 bytes total (10907648 bytes free)

Can you please advise what might be the cause for only the first 2 files getting created?

[Francesco Molino]

Hi

Just for doing test correctly, could you add the privilege 15 to your event manager session after the user keyword?

Also to check what's happening, could you run the debug command:

debug event manager action cli

Thanks.

PS: Please don't forget to rate and mark as correct answer if this solved your issue 

[Pradeep H A]

Hi supportlan,

I tried adding privilege 15 but looks like the option is not recognized

C3750(config)#event manager session cli username "user" privilege ?
% Unrecognized command

Also I learned the Action labelling in my script was wrong the next statement after 1.9 must be 2.0 not 1.10. The statement with label 1.10 was getting executed after 1.1. I corrected still problem remains

The below debug shows a cli_close is being called soon after the CLI command in the 5th line. not sure why?

I increased the polling interval & put up an exit time variable of 120 secs since I suspected the script is timing out before capturing all output but no luck. problem remains same.

event snmp oid 1.3.6.1.4.1.9.9.109.1.1.1.1.3.1 get-type exact entry-op gt entry-val 80 exit-op lt exit-val 70 exit-time 120 poll-interval 5

I increased the interval in the below command to try. but no luck. problem remains same

process cpu threshold type total rising 85 interval 30 falling 70 interval 30

079057: Jul  2 05:15:31.228: %HA_EM-6-LOG: cpu_stats-user: ------HIGH CPU DETECTED----, CPU: 99 %
079058: Jul  2 05:15:31.228: %HA_EM-6-LOG: cpu_stats-user: Finished gathering information to flash:cpu_stats-user.txt...
079059: Jul  2 05:17:21.565: %HA_EM-6-LOG: cpu_stats-user: ------HIGH CPU DETECTED----, CPU: 99 %
079060: Jul  2 05:17:21.565: %HA_EM-6-LOG: cpu_stats-user: Finished gathering information to flash:cpu_stats-user.txt...
079061: Jul  2 05:17:21.573: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : CTL : cli_open called.
079062: Jul  2 05:17:21.817: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : OUT : q
------Confidential information omitted ---------------------------------------------
079083: Jul  2 05:17:21.825: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : IN  : C3750>exit
079084: Jul  2 05:17:23.301: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : OUT : C3750>
079085: Jul  2 05:17:23.301: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : IN  : C3750>enable
079086: Jul  2 05:17:25.214: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : OUT : C3750#
079087: Jul  2 05:17:25.214: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : IN  : C3750#terminal length 0
079088: Jul  2 05:17:28.259: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : OUT : C3750#
079089: Jul  2 05:17:28.268: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : IN  : C3750#show clock | redirect flash:user-clock.txt
079090: Jul  2 05:17:28.385: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : OUT :
079091: Jul  2 05:17:28.385: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : OUT : C3750#
079092: Jul  2 05:17:28.385: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : IN  : C3750#show proc cpu sort | redirect flash:user-cpu.txt
079093: Jul  2 05:17:41.740: %HA_EM-6-LOG: cpu_stats-user : DEBUG(cli_lib) : : CTL : cli_close called.

[Francesco Molino]

Hi

It stops for unknown reason after the sh proc cpu sort.

Could you do it again with debug event manager all in order to get all eem messages?

Yes. For the number you have to set 2.0 instead of 1.10 but it was not important as your facing a write issue since the beginning on the flash.

Thanks

[Pradeep H A]

Hi supportlan,

I have uploaded the debug logs. Please have a look & advise. I have highlighted a line that shows the EEM script exited because a time out occured. I am not sure where in our configuration we have specified a time limit of 20 secs!

Thanks in advance

[Francesco Molino · Accepted solution]

Hi

20 seconds is the default timeout of eem.

you can increase it by addind maxrun keyword at the end of your event trigger.

could you, for test purpose, increase it to max 2 minutes and test again?

Thanks 

PS: Please don't forget to rate and mark as correct answer if this solved your issue 

[Pradeep H A]

hi supportlan,

Hurrah! Finally the issue is resolved. I had to increase the maxrun time to 3600 secs to get all the command outputs saved into the flash. I wonder what makes the command outputs take so long to get recorded into flash! Even when maxrun was configured at 15 mins, the last line output was missing. I then increased it to 3600 secs. now all the outputs i configured are getting captured.

Thanks a lot for your support!

[Francesco Molino]

You're very welcome 

[Jason M.]

What does "show event manager history events" show?

Also, is there no entries after the "show ver" you performed to create the file?