C3850 - Commands for troubleshooting high CPU - only one core

[Maarten Brok]

Through our monitoring system we saw an peak in the CPU usage on one of our C3850 switch stacks. We have now found out that switch one of the two, is running constantly on 99% usage for core 4.

I have already found out that the high core usage is only happening on switch 1. As the process is using 18.6% of my total CPU power, I suppose that the process is running on Core 4, which causes the high usage. The usage of the process is not extremely high or something, but I just want to know sure if this process is running on Core 4. So far I haven't been able to find out if there is any command which shows which process runs on which core of the processor. Anyone known with any kind of command?

PS: At the moment I was collecting the information, it looks like the process has changed from core as core 2 is now loaded much more.

System information:

                                             H/W   Current
Switch#   Role    Mac Address     Priority Version  State
------------------------------------------------------------
*1       Active     xxxx.xxxx.xxxx     1     V02     Ready
 2       Standby  yyyy.yyyy.yyyy     1      V02     Ready

Switch Ports Model              SW Version        SW Image              Mode
------ ----- -----              ----------        ----------            ----
*    1 20    WS-C3850-12S       03.07.04E         cat3k_caa-universalk9 INSTALL
     2 20    WS-C3850-12S       03.07.04E         cat3k_caa-universalk9 INSTALL

Switch uptime: 25 weeks, 4 days, 20 hours, 22 minutes

Logs regarding to the core load:

sh processes cpu detailed | ex 0.0
Core 0: CPU utilization for five seconds: 18%; one minute: 16%; five minutes: 16%
Core 1: CPU utilization for five seconds: 13%; one minute: 14%; five minutes: 15%
Core 2: CPU utilization for five seconds: 94%; one minute: 98%; five minutes: 86%
Core 3: CPU utilization for five seconds: 36%; one minute: 10%; five minutes: 8%
Core 4: CPU utilization for five seconds: 31%; one minute: 9%; five minutes: 19%
Core 5: CPU utilization for five seconds: 8%; one minute: 3%; five minutes: 3%
PID     T C  TID     Runtime(ms) Invoked   uSecs  5Sec   1Min 5Min TTY   Process
                                                  (%)    (%)  (%)
6393    L            3176069     225763674 128    18.4   18.8 18.7 1088  fed
6393    L 0  6834    3172964     45464774  0      0.16   0.19 0.19 1088  fed
6393    L 5  6840    331310      335555045 0      0.22   0.21 0.22 0     fed-ots-main
6393    L 5  6843    3828438     28986386  0      1.03   1.23 1.18 0     fed-ots-nfl
6393    L 2  11995   3356383     134096271 0      15.9   16.2 16.2 0     PunjectRx
6964    L            3241129     120223180 41     0.39   0.15 0.13 0     pdsd
6964    L 0  9222    3043397     851647554 0      0.39   0.15 0.13 0     pdsd
6966    L            2154450     19446762  110    0.29   0.24 0.46 0     osinfo-provider
6966    L 3  9155    1237590     690334    0      0.19   1.67 0.25 0     eicore_ipc
6972    L            4227667     602848536 78     0.10   0.24 0.23 0     ffm
6973    L            687732      161259300 323    1.06   0.65 0.43 0     eicored
6973    L 3  9170    2622532     18431484  0      1.03   0.59 1.13 0     eicore_ipc
11271   L 5  11271   2184320     127462722 0      1.82   1.89 1.83 0     iosd
30      I            788408      159135877 0      0.22   0.22 0.22 0       ARP Input
180     I            1465591     932260488 0      1.55   2.66 2.55 0       ACL Logging Proce
255     I            3925288     156857768 0      1.11   0.44 0.44 0       Spanning Tree
362     I            2784838     1623634   0      0.22   0.11 0.11 0       QoS stats process

sh processes cpu detailed switch 1 | ex 0.0
Core 0: CPU utilization for five seconds: 23%; one minute: 13%; five minutes: 12%
Core 1: CPU utilization for five seconds: 18%; one minute: 18%; five minutes: 12%
Core 2: CPU utilization for five seconds: 18%; one minute: 8%; five minutes: 5%
Core 3: CPU utilization for five seconds: 6%; one minute: 19%; five minutes: 7%
Core 4: CPU utilization for five seconds: 99%; one minute: 98%; five minutes: 99%
Core 5: CPU utilization for five seconds: 37%; one minute: 9%; five minutes: 5%
PID     T C  TID     Runtime(ms) Invoked   uSecs  5Sec   1Min 5Min TTY   Process
                                                  (%)    (%)  (%)
6393    L            2487129     223966348 128    18.5   18.5 18.6 1088  fed
6393    L 0  6834    3166084     45461401  0      0.16   0.15 0.16 1088  fed
6393    L 3  6840    330110      335541495 0      0.49   0.39 0.38 0     fed-ots-main
6393    L 5  6843    3788658     28984564  0      0.75   1.02 1.03 0     fed-ots-nfl
6393    L 0  10630   1972547     337119101 0      0.33   0.25 0.24 0     Xcvr
6393    L 4  11995   2749583     134055797 0      16.3   16.2 16.2 0     PunjectRx
6393    L 2  11998   2047305     186095751 0      0.23   0.16 0.17 0     PunjectTx
6972    L            4224397     602820075 78     0.33   0.23 0.25 0     ffm
11271   L            376199      263139951 98     2.59   2.77 2.86 0     iosd
11271   L 2  11271   2132920     127415268 0      1.44   1.30 1.34 0     iosd
11271   L 0  12148   3047871     121263239 0      1.12   1.44 1.48 0     iosd.fastpath
7       I            3533228     3488918   0      1.33   0.22 0.11 0       Check heaps
22      I            825179      95155691  0      0.11   0.22 0.22 0       CMI IOSd task
30      I            786868      159126744 0      1.00   0.22 0.22 0       ARP Input
220     I            1998832     155066981 0      0.22   0.11 0.11 0       Tunnel IOSd shim

sh processes cpu detailed switch 2 | ex 0.0
Core 0: CPU utilization for five seconds: 5%; one minute: 6%; five minutes: 6%
Core 1: CPU utilization for five seconds: 5%; one minute: 1%; five minutes: 1%
Core 2: CPU utilization for five seconds: 1%; one minute: 1%; five minutes: 1%
Core 3: CPU utilization for five seconds: 0%; one minute: 5%; five minutes: 5%
Core 4: CPU utilization for five seconds: 4%; one minute: 2%; five minutes: 2%
Core 5: CPU utilization for five seconds: 1%; one minute: 1%; five minutes: 1%
PID     T C  TID     Runtime(ms) Invoked   uSecs  5Sec   1Min 5Min TTY   Process
                                                  (%)    (%)  (%)
6304    L 5  6751    2408848     334282797 0      0.23   0.47 0.46 1088  fed-ots-main
6304    L 0  10732   4157104     354987654 0      0.29   0.24 0.24 0     Xcvr
6881    L 0  8004    299990      15591648  0      0.46   0.46 0.46 0     os_info_p
6887    L 1  9140    52940       377170926 0      0.16   0.16 0.21 0     CMI default xdm
11853   L            2214985     500874125 45     0.23   0.24 0.24 0     iosd
11853   L 0  11853   2608212     469946657 0      0.13   0.22 0.23 0     iosd
361     I            2684068     1566277   0      0.22   0.11 0.11 0       QoS stats process

[Iulian Vaideanu]

I've never worked with the C3850, but I found this doc:

http://www.cisco.com/c/en/us/support/docs/switches/catalyst-3850-series-switches/117594-technote-hicpu3850-00.html

[Maarten Brok]

Hi Iulian,

I have read the document earlier also, thanks for helping, unfortunately the document doesn't provide me the answer I am looking for :(

Have a nice day!

[Iulian Vaideanu]

My apologies, I didn't read very carefully, I just assumed the issue was about finding out what causes the high CPU load...

I can't find any reference for the "show proc cpu detailed" output, but it looks safe to assume that the "C" column stands for "core" - on a C4500X (also IOS XE based, also multi-core), "sh proc cpu detailed | i ^PID|[0-9]+[ ]+[A-Z][ ]1" seems to output the list of processes / threads running on core 1.

[Maarten Brok]

I understand, no problem!

Good thinking, seems logical, looking at the fact we have 6 cores available:
Process PunjectRX is likely running on core 4, with a load of 16.3% of the total processor power it would likely use 97.8% of core 4. Which is relatable to the high load of core 4.

So possibly we can also assume that the 'FED' process is running on multiple cores as it has no core number available.

Hope someone has the knowledge to tell us we are correct :)

Thanks so far Iulian!

[Iulian Vaideanu · Accepted solution]

Most likely all processes run on multiple cores - for each process there should be as many lines containing a core number as there are threads in the process (the TID (thread_id, I guess) column differs) and one "totaling" line without a core number.

Again, this is empirical observation, not authoritative knowledge :)...

[Maarten Brok]

Hi Iulian,

I have been waiting for other answers, but as they likely are not coming, I think we should do it with our investigation :)

Your last reply seems logical to me, looking at the processes running currently I see there is now a higher load on core 1. Given that the process is switching I assume it doesn't harm my device.

I will close this ticket, thanks for you help and have a nice day!!