CPU spikes periodically after upgrade

[Michio]

Hi.

I upgraded the OS from 6.0.9 to 6.4.9.

After the upgrade, CPU usage started to spike periodically and momentarily.

It doesn't happen every day. Occasionally occurs.
One day it happened every hour.

Just for a second, I noticed that the wad process was causing CPU usage to rise.

Is there a way to investigate the cause in detail?

This is monitor Image.(By Zabbix)

After 07/23 5:00, 6:00, 7:00 .... , and it's stopped.

What's happen?

This machine is stand-by, No one use.

I found the WAD process running when the CPU was spiking, is it possible to inspect the details of the WAD process?

Run Time:  3 days, 21 hours and 29 minutes
72U, 0N, 0S, 28I, 0WA, 0HI, 0SI, 0ST; 3039T, 1722F
             wad      221      R      89.7     0.8
             wad      210      R      82.3     0.9
             wad      211      R      57.3     0.8
             wad      212      R      56.3     0.8
        bcm.user       94      S <     3.4     0.4
          newcli    13906      R       0.9     0.2
       ipsengine      285      S <     0.4     2.3
          hasync      179      S <     0.4     0.4
 initXXXXXXXXXXX        1      S       0.4     0.4
          hatalk      178      S <     0.4     0.2
            sshd    13902      S       0.4     0.2
       ipsengine      287      S <     0.0     2.2
       ipsengine      289      S <     0.0     2.2
       ipsengine      286      S <     0.0     2.2
         cmdbsvr      122      S       0.0     1.2
       ipshelper      195      S <     0.0     1.0
         miglogd      150      S       0.0     0.8
         miglogd      241      S       0.0     0.6
         miglogd      240      S       0.0     0.6
          cw_acd      213      S       0.0     0.6
         updated      269      S       0.0     0.6
       scanunitd      176      S <     0.0     0.6
       scanunitd    13864      S <     0.0     0.5
       forticron      162      S       0.0     0.5
          httpsd      155      S       0.0     0.5
            node      156      S       0.0     0.5
           fgfmd      208      S       0.0     0.4
          newcli    13903      S       0.0     0.4
             wad      205      S       0.0     0.4
        dnsproxy      215      S       0.0     0.4

[Anthony_E]

Hello Michio,

Thank you for using the Community Forum.

I will seek to get you an answer or help. We will reply to this thread with an update as soon as possible.

Regards,

[sjoshi]

Dear Michio,

Thank you for posting to the Fortinet Community Forum.

Problem Description:-
CPU spikes periodically after upgrade

Please share us the following output:-
#diag sys flash list
#get system status
#get hardware status
#get system performance status (run this command 5 times in interval of 1 minutes)
#diag sys top 1 40 (Run for 30 Sec and CTRL C to stop)
#diag sys top-summary (Run for 30 Sec and CTRL C to stop)
#diagnose autoupdate versions
#diag hard sys mem
#diag hard sys cpu
#diag sys session stat
#diag debug crashlog read
# diagnose hardware deviceinfo disk
# get log gui-display
# get log disk setting
# get log memory setting
#diagnose sys mpstat (Run for 30 Sec and CTRL C to stop)

fnsysctl ps aux
fnsysctl cat /proc/stat
fnsysctl cat /proc/interrupts
fnsysctl cat /proc/softirqs
fnsysctl cat /proc/net/sockstat

Thanks

[Michio]

Thank you for your reply.

There are too many outputs, so I can't paste it in one time, so I will divide it into several times and paste it.

[Michio]

FW-01 # get system performance status
CPU states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU0 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU1 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU2 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU3 states: 3% user 0% system 0% nice 97% idle 0% iowait 0% irq 0% softirq
Memory: 3112492k total, 1193296k used (38.3%), 1717320k free (55.2%), 201876k freeable (6.5%)
Average network usage: 89 / 88 kbps in 1 minute, 161 / 160 kbps in 10 minutes, 386 / 385 kbps in 30 minutes
Average sessions: 113 sessions in 1 minute, 137 sessions in 10 minutes, 130 sessions in 30 minutes
Average session setup rate: 1 sessions per second in last 1 minute, 0 sessions per second in last 10 minutes, 0 sessions per second in last 30 minutes
Average NPU sessions: 6 sessions in last 1 minute, 5 sessions in last 10 minutes, 5 sessions in last 30 minutes
Average nTurbo sessions: 0 sessions in last 1 minute, 0 sessions in last 10 minutes, 0 sessions in last 30 minutes
Virus caught: 0 total in 1 minute
IPS attacks blocked: 0 total in 1 minute
Uptime: 13 days, 1 hours, 53 minutes

FW-01 # get system performance status
CPU states: 1% user 0% system 0% nice 99% idle 0% iowait 0% irq 0% softirq
CPU0 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU1 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU2 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU3 states: 2% user 0% system 0% nice 98% idle 0% iowait 0% irq 0% softirq
Memory: 3112492k total, 1193304k used (38.3%), 1717312k free (55.2%), 201876k freeable (6.5%)
Average network usage: 474 / 472 kbps in 1 minute, 160 / 159 kbps in 10 minutes, 386 / 385 kbps in 30 minutes
Average sessions: 116 sessions in 1 minute, 136 sessions in 10 minutes, 130 sessions in 30 minutes
Average session setup rate: 1 sessions per second in last 1 minute, 0 sessions per second in last 10 minutes, 0 sessions per second in last 30 minutes
Average NPU sessions: 6 sessions in last 1 minute, 5 sessions in last 10 minutes, 5 sessions in last 30 minutes
Average nTurbo sessions: 0 sessions in last 1 minute, 0 sessions in last 10 minutes, 0 sessions in last 30 minutes
Virus caught: 0 total in 1 minute
IPS attacks blocked: 0 total in 1 minute
Uptime: 13 days, 1 hours, 53 minutes

[Michio]

FW-01 # get system performance status
CPU states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU0 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU1 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU2 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU3 states: 2% user 0% system 0% nice 98% idle 0% iowait 0% irq 0% softirq
Memory: 3112492k total, 1193536k used (38.3%), 1717080k free (55.2%), 201876k freeable (6.5%)
Average network usage: 1133 / 1131 kbps in 1 minute, 260 / 258 kbps in 10 minutes, 386 / 385 kbps in 30 minutes
Average sessions: 118 sessions in 1 minute, 133 sessions in 10 minutes, 130 sessions in 30 minutes
Average session setup rate: 1 sessions per second in last 1 minute, 0 sessions per second in last 10 minutes, 0 sessions per second in last 30 minutes
Average NPU sessions: 5 sessions in last 1 minute, 5 sessions in last 10 minutes, 5 sessions in last 30 minutes
Average nTurbo sessions: 0 sessions in last 1 minute, 0 sessions in last 10 minutes, 0 sessions in last 30 minutes
Virus caught: 0 total in 1 minute
IPS attacks blocked: 0 total in 1 minute
Uptime: 13 days, 1 hours, 54 minutes

FW-01 # get system performance status
CPU states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU0 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU1 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU2 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU3 states: 1% user 0% system 0% nice 99% idle 0% iowait 0% irq 0% softirq
Memory: 3112492k total, 1193412k used (38.3%), 1717204k free (55.2%), 201876k freeable (6.5%)
Average network usage: 585 / 577 kbps in 1 minute, 288 / 286 kbps in 10 minutes, 422 / 420 kbps in 30 minutes
Average sessions: 123 sessions in 1 minute, 130 sessions in 10 minutes, 128 sessions in 30 minutes
Average session setup rate: 1 sessions per second in last 1 minute, 0 sessions per second in last 10 minutes, 0 sessions per second in last 30 minutes
Average NPU sessions: 6 sessions in last 1 minute, 5 sessions in last 10 minutes, 4 sessions in last 30 minutes
Average nTurbo sessions: 0 sessions in last 1 minute, 0 sessions in last 10 minutes, 0 sessions in last 30 minutes
Virus caught: 0 total in 1 minute
IPS attacks blocked: 0 total in 1 minute
Uptime: 13 days, 1 hours, 55 minutes

FW-01 # get system performance status
CPU states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU0 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU1 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU2 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU3 states: 2% user 0% system 0% nice 98% idle 0% iowait 0% irq 0% softirq
Memory: 3112492k total, 1193164k used (38.3%), 1717452k free (55.2%), 201876k freeable (6.5%)
Average network usage: 93 / 89 kbps in 1 minute, 301 / 300 kbps in 10 minutes, 406 / 404 kbps in 30 minutes
Average sessions: 127 sessions in 1 minute, 129 sessions in 10 minutes, 127 sessions in 30 minutes
Average session setup rate: 0 sessions per second in last 1 minute, 0 sessions per second in last 10 minutes, 0 sessions per second in last 30 minutes
Average NPU sessions: 6 sessions in last 1 minute, 5 sessions in last 10 minutes, 4 sessions in last 30 minutes
Average nTurbo sessions: 0 sessions in last 1 minute, 0 sessions in last 10 minutes, 0 sessions in last 30 minutes
Virus caught: 0 total in 1 minute
IPS attacks blocked: 0 total in 1 minute
Uptime: 13 days, 1 hours, 56 minutes

FW-01 # get system performance status
CPU states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU0 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU1 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU2 states: 0% user 0% system 0% nice 100% idle 0% iowait 0% irq 0% softirq
CPU3 states: 3% user 0% system 0% nice 97% idle 0% iowait 0% irq 0% softirq
Memory: 3112492k total, 1193048k used (38.3%), 1717568k free (55.2%), 201876k freeable (6.5%)
Average network usage: 96 / 89 kbps in 1 minute, 283 / 281 kbps in 10 minutes, 406 / 404 kbps in 30 minutes
Average sessions: 116 sessions in 1 minute, 127 sessions in 10 minutes, 127 sessions in 30 minutes
Average session setup rate: 0 sessions per second in last 1 minute, 0 sessions per second in last 10 minutes, 0 sessions per second in last 30 minutes
Average NPU sessions: 6 sessions in last 1 minute, 5 sessions in last 10 minutes, 4 sessions in last 30 minutes
Average nTurbo sessions: 0 sessions in last 1 minute, 0 sessions in last 10 minutes, 0 sessions in last 30 minutes
Virus caught: 0 total in 1 minute
IPS attacks blocked: 0 total in 1 minute
Uptime: 13 days, 1 hours, 57 minutes

[Michio]

FW-01 # diagnose autoupdate versions

AV Engine
---------
Version: 6.00170
Contract Expiry Date: Mon Jun 12 2023
Last Updated using manual update on Fri May 17 18:00:05 2019
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: No Updates

Virus Definitions
---------
Version: 90.04734
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

Extended set
---------
Version: 90.04734
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

Mobile Malware Definitions
---------
Version: 90.04734
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

IPS Attack Engine
---------
Version: 6.00122
Contract Expiry Date: Mon Jun 12 2023
Last Updated using manual update on Sat Apr 9 00:58:00 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: No Updates

IPS Config Script
---------
Version: 1.00009
Contract Expiry Date: Mon Jun 12 2023
Last Updated using manual update on Thu Jun 6 14:02:00 2019
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: No Updates

Attack Definitions
---------
Version: 21.00367
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

Attack Extended Definitions
---------
Version: 0.00000
Contract Expiry Date: Mon Jun 12 2023
Last Updated using manual update on Mon Jan 1 00:00:00 2001
Last Update Attempt: Wed Jul 1 01:52:17 2020
Result: Connectivity failure

Application Definitions
---------
Version: 21.00366
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

Industrial Attack Definitions
---------
Version: 6.00741
Contract Expiry Date: n/a
Last Updated using manual update on Tue Dec 1 02:30:00 2015
Last Update Attempt: n/a
Result: Updates Installed

IPS Malicious URL Database
---------
Version: 4.00427
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

Flow-based Virus Definitions
---------
Version: 90.04334
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Fri Jul 22 01:07:05 2022
Last Update Attempt: Fri Jul 22 01:07:58 2022
Result: No Updates

Botnet Domain Database
---------
Version: 3.00058
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

Internet-service Database Apps
---------
Version: 7.02566
Contract Expiry Date: n/a
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

Internet-service Database Maps
---------
Version: 7.02566
Contract Expiry Date: n/a
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

Device and OS Identification
---------
Version: 1.00138
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Fri Jul 8 01:07:40 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: No Updates

URL White list
---------
Version: 3.00580
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Thu Aug 4 01:49:58 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: Updates Installed

IP Geography DB
---------
Version: 3.00136
Contract Expiry Date: n/a
Last Updated using scheduled update on Sun Jul 31 01:49:23 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: No Updates

Certificate Bundle
---------
Version: 1.00034
Contract Expiry Date: n/a
Last Updated using manual update on Tue Apr 26 17:08:00 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: No Updates

Malicious Certificate DB
---------
Version: 1.00385
Contract Expiry Date: Mon Jun 12 2023
Last Updated using scheduled update on Wed Aug 3 01:49:19 2022
Last Update Attempt: Thu Aug 4 01:49:58 2022
Result: No Updates

Modem List
---------
Version: 0.000

FDS Address
---------
173.243.129.6:443

[Michio]

FW-01 # diag hard sys mem
MemTotal: 3112492 kB
MemFree: 1716444 kB
Buffers: 88144 kB
Cached: 521104 kB
SwapCached: 0 kB
Active: 639996 kB
Inactive: 272536 kB
Active(anon): 493996 kB
Inactive(anon): 165680 kB
Active(file): 146000 kB
Inactive(file): 106856 kB
Unevictable: 0 kB
Mlocked: 0 kB
HighTotal: 270336 kB
HighFree: 396 kB
LowTotal: 2842156 kB
LowFree: 1716048 kB
SwapTotal: 0 kB
SwapFree: 0 kB
Dirty: 0 kB
Writeback: 0 kB
AnonPages: 303344 kB
Mapped: 139244 kB
Shmem: 356392 kB
Slab: 90440 kB
SReclaimable: 7924 kB
SUnreclaim: 82516 kB
KernelStack: 1280 kB
PageTables: 18700 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 1556244 kB
Committed_AS: 7789304 kB
VmallocTotal: 245760 kB
VmallocUsed: 141424 kB
VmallocChunk: 55404 kB

FW-01 # diag hard sys cpu
Processor : ARMv7 Processor rev 1 (v7l)
processor : 0
BogoMIPS : 2007.04

processor : 1
BogoMIPS : 2007.04

processor : 2
BogoMIPS : 2007.04

processor : 3
BogoMIPS : 2007.04

Features : swp half thumb fastmult vfp edsp thumbee vfpv3 vfpv3d16 tls
CPU implementer : 0x41
CPU architecture: 7
CPU variant : 0x4
CPU part : 0xc09
CPU revision : 1

Hardware : FSoC3_ASIC
Revision : 0000
Serial : 0000000000000000

FW-01 # diag sys session stat
misc info: session_count=151 setup_rate=0 exp_count=0 clash=8
memory_tension_drop=0 ephemeral=0/196608 removeable=0
npu_session_count=6
nturbo_session_count=0
delete=4, flush=0, dev_down=42/305 ses_walkers=0
TCP sessions:
1 in NONE state
25 in ESTABLISHED state
1 in CLOSE state
firewall error stat:
error1=00000000
error2=00000000
error3=00000000
error4=00000000
tt=00000000
cont=00415e0d
ids_recv=0128927c
url_recv=00000000
av_recv=01e84568
fqdn_count=00000007
fqdn6_count=00000000
global: ses_limit=0 ses6_limit=0 rt_limit=0 rt6_limit=0

FW-01 # diag debug crashlog read
1: 2022-07-22 11:41:16 the killed daemon is /bin/updated: status=0x0
2: 2022-07-22 11:46:18 the killed daemon is /bin/getty: status=0x9
3: 2022-07-22 12:01:28 the killed daemon is /bin/getty: status=0x0
4: 2022-07-22 12:22:36 the killed daemon is /bin/updated: status=0x0
5: 2022-07-22 12:36:04 the killed daemon is /bin/updated: status=0x0
6: 2022-07-22 12:36:09 the killed daemon is /bin/hatalk: status=0x0
7: 2022-07-22 12:36:11 Interface dmz is brought down. process_id=1280, process_name="httpsd"
8: 2022-07-22 12:36:11 Interface mgmt is brought down. process_id=1280, process_name="httpsd"
9: 2022-07-22 12:36:12 Interface wan1 is brought down. process_id=1280, process_name="httpsd"
10: 2022-07-22 12:36:12 Interface wan2 is brought down. process_id=1280, process_name="httpsd"
11: 2022-07-22 12:36:12 Interface ha1 is brought down. process_id=1280, process_name="httpsd"
12: 2022-07-22 12:36:12 Interface ha2 is brought down. process_id=1280, process_name="httpsd"
13: 2022-07-22 12:36:12 Interface port1 is brought down. process_id=1280, process_name="httpsd"
14: 2022-07-22 12:36:12 Interface port2 is brought down. process_id=1280, process_name="httpsd"
15: 2022-07-22 12:36:12 Interface port3 is brought down. process_id=1280, process_name="httpsd"
16: 2022-07-22 12:36:12 Interface port4 is brought down. process_id=1280, process_name="httpsd"
17: 2022-07-22 12:36:13 Interface port5 is brought down. process_id=1280, process_name="httpsd"
18: 2022-07-22 12:36:13 Interface port6 is brought down. process_id=1280, process_name="httpsd"
19: 2022-07-22 12:36:13 Interface port7 is brought down. process_id=1280, process_name="httpsd"
20: 2022-07-22 12:36:13 Interface port8 is brought down. process_id=1280, process_name="httpsd"
21: 2022-07-22 12:36:13 Interface port9 is brought down. process_id=1280, process_name="httpsd"
22: 2022-07-22 12:36:13 Interface port10 is brought down. process_id=1280, process_name="httpsd"
23: 2022-07-22 12:36:13 Interface port11 is brought down. process_id=1280, process_name="httpsd"
24: 2022-07-22 12:36:14 Interface port12 is brought down. process_id=1280, process_name="httpsd"
25: 2022-07-22 12:36:14 Interface port13 is brought down. process_id=1280, process_name="httpsd"
26: 2022-07-22 12:36:14 Interface port14 is brought down. process_id=1280, process_name="httpsd"
27: 2022-07-22 12:36:14 Interface port15 is brought down. process_id=1280, process_name="httpsd"
28: 2022-07-22 12:36:14 Interface port16 is brought down. process_id=1280, process_name="httpsd"
29: 2022-07-22 12:56:09 the killed daemon is /bin/getty: status=0x0
Crash log interval is 3600 seconds
Max crash log line number: 16384

[Michio]

Additional information.

I got a debug log for the WAD process when the CPU was spiking.
(diagnose wad debug enable category all)

Got it 3 times.

Log output:
[p:211]wad_ssh_untrusted_hostkey_timeout(1467): unstrusted hostkey set regenerated

same logs.

I think this is what is causing the CPU to spike.

But I don't understand what the log means.