Cisco Router CPU Profiling

The symptom of high CPU utilization due to interrupts on Cisco devices can be observed using the show processes cpu EXEC command. Below shows the format of the 1st line of the output of the show processes cpu EXEC command:
CPU utilization for five seconds: A%/B%; one minute: C%; five minutes: D%

A	Average CPU utilization due to interrupts and processes during last 5 seconds.
B	Average CPU utilization due to interrupts only during last 5 seconds.
C	Average CPU utilization during last minute.
D	Average CPU utilization during last 5 minutes.

Note: A = B + CPU utilization of other active processes.

High CPU utilization on an interrupt level is often caused by packets being handled on interrupt level due to various reasons. CPU profiling is able to determine root cause of such high CPU utilization problems.

CPU profiling is a low-overhead way of determining where the CPU spends its time. It works by sampling the processor location every 4ms, and increments the counts for the memory locations.

Below lists the steps for performing CPU profiling on a Cisco 3620 router with 32MB DRAM:
1) Log the output of all commands into a text file.
2) Issue the show region privileged command to display the starting and ending addresses, and the size of the main:text region.

Router#sh ver | in IOS|bytes of memory
IOS (tm) 3600 Software (C3620-I-M), Version 12.3(26), RELEASE SOFTWARE (fc2)
cisco 3620 (R4700) processor (revision 0xFF) with 28672K/4096K bytes of memory.
Router#
Router#sh region
Region Manager:

      Start         End     Size(b)  Class  Media  Name
 0x01C00000  0x01FFFFFF     4194304  Iomem  R/W    iomem
 0x30000000  0x307FFFFF     8388608  Flash  R/O    flash
 0x60000000  0x61BFFFFF    29360128  Local  R/W    main
 0x60008B00  0x60CF6207    13555464  IText  R/O    main:text
 0x60CF8000  0x6129C0DF     5914848  IData  R/W    main:data
 0x6110EB60  0x6115139F      272448  Local  R/W    data:firmware
 0x6129C0E0  0x6149F85F     2111360  IBss   R/W    main:bss
 0x6149F860  0x61BFFFFF     7735200  Local  R/W    main:heap
 0x80000000  0x81BFFFFF    29360128  Local  R/W    main:(main_k0)
 0xA0000000  0xA1BFFFFF    29360128  Local  R/W    main:(main_k1)


Router#

3) Issue the show memory statistics privileged command to display the size of the largest block of free processor memory.

Router#sh memory statistics
                Head    Total(b)     Used(b)     Free(b)   Lowest(b)  Largest(b)
Processor   6149F860     8007648     3830368     4177280     4165160     3779480
      I/O    1C00000     4194304     1947144     2247160     2239408     2239676
Router#

4) Compare the size of the main:text region with the size of the largest block of free processor memory. Ideally the largest block should be larger than the main:text region.
- If the largest block is larger than main:text region, use a granularity value of 4.
- If the largest block is larger than half of the main:text region, use a granularity value of 8.
- If the largest block is larger than quarter of the main:text region, use a granularity value of 10 (16 in hexadecimal).
5) Stop any CPU profiling that could have been performed without proper clean using with the profile stop, clear profile, and unprofile all privileged commands.
6) Issue the profile task interrupt privileged command to enable CPU profiling only for interrupts.
7) Issue the profile {main:text_start-addr} {main:text_end-addr} {granularity} privileged command to start CPU profiling. The command used for this example is profile 60008B00 60CF6207 10.
Note: Largest block (3779480) is larger than quarter of the main:text region (13555464 / 4 = 3388866).
8) Issue the show clock command to display the time the CPU profiling is started.
9) Wait for 5 to 10 minutes.
10) Issue the profile stop privileged command to stop CPU profiling.
11) Issue the show clock command to display the time the CPU profiling is stopped.
12) Issue the following privileged commands:
show profile terse
show tech cef
show align
show stack
13) Issue the clear profile privileged command to clear the CPU profiling statistics.
14) Issue the unprofile all privileged command to release and reclaim the memory resources used for CPU profiling.

Router#sh memory statistics
                Head    Total(b)     Used(b)     Free(b)   Lowest(b)  Largest(b)
Processor   6149F860     8007648     7236932      770716      765928      272404
      I/O    1C00000     4194304     1914584     2279720     2279720     2279676
Router#
Router#unprofile all
Router#sh memory statistics
                Head    Total(b)     Used(b)     Free(b)   Lowest(b)  Largest(b)
Processor   6149F860     8007648     3848048     4159600      765928     3505792
      I/O    1C00000     4194304     1914584     2279720     2279720     2279676
Router#

Note: The profile privileged command is a hidden and undocumented Cisco IOS command.