FortiGate
FortiGate Next Generation Firewall utilizes purpose-built security processors and threat intelligence security services from FortiGuard labs to deliver top-rated protection and high performance, including encrypted traffic.
sgiannogloudis
Article Id 288758
Description This article describes how to identify the root cause of an hasync high CPU utilization.
Scope FortiGate v6.x and v7.x.
Solution

Let's assume a network administrator identifies that his device has high CPU usage on one of its CPU cores.

 

By issuing the command 'diagnose sys top 1 20 6' it has been identified that hasync is consuming the majority of the CPU cycles:

 

diagnose sys top 1 20 6

Run Time: 2 days, 13 hours and 23 minutes
2U, 0N, 5S, 52I, 0WA, 0HI, 41SI, 0ST; 15918T, 9814F
hasync 270 R < 92.0 0.1 11

 

While the issue is happening, it is recommended to issue the command 'diag sys ha hasync-stats most-recent' a couple of times.

 

The output of the particular command was omitted for easier reading.

 

diag sys ha hasync-stats most-recent 


current-time/jiffies=2023-11-01 15:20:03/128549723:

 

hasync-obj=1(fdb):
obj_handler=1(msg): total_time/call=336.366348/101789/101789
obj_handler=3(event): total_time/call=0.000081/4/4
obj_handler=4(command): total_time/call=0.003103/26186/26186
epoll_handler=0(fdb_handler): total_time/call=369550.646290/2283433136/2283433136


hasync-obj=2(arp):
obj_handler=0(packet): total_time/call=0.026781/232/232
obj_handler=3(event): total_time/call=0.000006/4/4
epoll_handler=1(ev_arp_handler): total_time/call=674.748711/6287738/6287738

 

diag sys ha hasync-stats most-recent
current-time/jiffies=2023-11-01 15:20:08/128550252:

 

hasync-obj=1(fdb):
obj_handler=1(msg): total_time/call=336.366348/101789/101789
obj_handler=3(event): total_time/call=0.000081/4/4
obj_handler=4(command): total_time/call=0.003103/26186/26186
epoll_handler=0(fdb_handler): total_time/call=369552.167399/2284104510/2284104509


hasync-obj=2(arp):
obj_handler=0(packet): total_time/call=0.026781/232/232
obj_handler=3(event): total_time/call=0.000006/4/4
epoll_handler=1(ev_arp_handler): total_time/call=674.749423/6287788/6287788

 

The output indicates the modules and the submodules, respectively, which mainly occupy the hasync CPU time.

 

By that time, the majority of the CPU cycle consumers were:

 

  1. FDB: Forwarding Database.
  2. ARP: Address Resolution Protocol.

 

By examining the submodules it is possible to observe the 'fdb_handler' total call times are exponentially increasing between the two iterations of the commands so to calculate the amount of times which the particular submodule is being called, it is necessary to perform the below calculation:

 

(2284104509 - 2283433136) / 5 =  134,274.

 

  • Inside the parentheses is the subtraction of the total amount of times the submodule is called between the two command iterations.
  • The number 5 is the time difference between the iterations of the two commands [The first line of the output prints the timestamp when the command was issued].

 

Thus, from the above result, the conclusion is that hasync tries to sync 134k/s of forwarding database information to the secondary unit which can result from abnormal L2 traffic or a loop in the L2 infrastructure.