Cross-checking outputs
This is to verify the results provided by this utility match the reality.
cputop
Following commands were run via the standard FortiGate CLI and also using this utility. The collection interval was 5 seconds in both cases and they were synchronized to calculate the results over the same interval.
In can be seen that TOTAL% from flhcli output matches the CPU column from diagnose sys top with
a great precision.
FGT37D-2 # diagnose sys top 5 50
ipsengine 566 S < 43.4 0.1
ipsengine 563 R < 40.2 0.1
ipsengine 578 S < 25.4 0.1
ipsengine 574 S < 25.2 0.1
ipsengine 575 R < 25.0 0.1
ipsengine 554 S < 23.9 0.1
ipsengine 565 S < 23.9 0.1
ipsengine 547 S < 23.7 0.1
ipsengine 553 S < 23.7 0.1
ipsengine 552 S < 23.5 0.1
ipsengine 556 S < 23.5 0.1
ipsengine 570 S < 23.3 0.1
ipsengine 564 S < 23.3 0.1
ipsengine 548 S < 23.3 0.1
ipsengine 557 R < 23.1 0.1
ipsengine 561 R < 23.1 0.1
ipsengine 559 S < 22.9 0.1
ipsengine 569 S < 22.9 0.1
ipsengine 568 S < 22.9 0.1
ipsengine 555 S < 22.5 0.1
ipsengine 573 R < 22.5 0.1
ipsengine 576 S < 22.3 0.1
ipsengine 571 S < 22.3 0.1
ipsengine 551 S < 22.3 0.1
ipsengine 567 S < 22.3 0.1
ipsengine 577 R < 21.9 0.1
ipsengine 549 S < 21.9 0.1
ipsengine 550 R < 21.9 0.1
ipsengine 560 S < 21.3 0.1
ipsengine 562 S < 21.1 0.1
ipsengine 572 S < 20.5 0.1
ipsengine 558 S < 20.1 0.1
flhcli --name FGT37D-2 cputop --parent ipsmon --max 35
PROCESS PID | PPID PARENT | S NICE | USER% SYSTEM% TOTAL% | CPU | RUNNING FOR |
-------------------------|--------------------------|---------|----------------------------|------|------------------|
ipsengine 566 | 413 ipsmonitor | S -5 | 32.5 10.8 43.3 | 28 | 13d 19h 48m 02s |
ipsengine 563 | 413 ipsmonitor | S -5 | 27.7 12.4 40.1 | 25 | 13d 19h 48m 02s |
ipsengine 574 | 413 ipsmonitor | R -5 | 15.8 9.6 25.5 | 3 | 13d 19h 48m 02s |
ipsengine 578 | 413 ipsmonitor | S -5 | 15.2 10.2 25.5 | 12 | 13d 19h 48m 02s |
ipsengine 575 | 413 ipsmonitor | R -5 | 14.6 10.6 25.3 | 8 | 13d 19h 48m 02s |
ipsengine 565 | 413 ipsmonitor | R -5 | 14.8 9.2 24.1 | 16 | 13d 19h 48m 02s |
ipsengine 553 | 413 ipsmonitor | R -5 | 13.8 10.0 23.9 | 35 | 13d 19h 48m 02s |
ipsengine 547 | 413 ipsmonitor | R -5 | 15.6 8.0 23.7 | 7 | 13d 19h 48m 02s |
ipsengine 552 | 413 ipsmonitor | S -5 | 14.6 9.0 23.7 | 31 | 13d 19h 48m 02s |
ipsengine 554 | 413 ipsmonitor | S -5 | 13.2 10.4 23.7 | 39 | 13d 19h 48m 02s |
ipsengine 564 | 413 ipsmonitor | S -5 | 13.0 10.6 23.7 | 29 | 13d 19h 48m 02s |
ipsengine 556 | 413 ipsmonitor | R -5 | 15.0 8.4 23.5 | 10 | 13d 19h 48m 02s |
ipsengine 548 | 413 ipsmonitor | S -5 | 13.6 9.6 23.3 | 15 | 13d 19h 48m 02s |
ipsengine 557 | 413 ipsmonitor | S -5 | 14.4 8.8 23.3 | 14 | 13d 19h 48m 02s |
ipsengine 570 | 413 ipsmonitor | S -5 | 13.6 9.6 23.3 | 17 | 13d 19h 48m 02s |
ipsengine 561 | 413 ipsmonitor | R -5 | 13.8 9.2 23.1 | 34 | 13d 19h 48m 02s |
ipsengine 568 | 413 ipsmonitor | S -5 | 14.8 8.0 22.9 | 9 | 13d 19h 48m 02s |
ipsengine 559 | 413 ipsmonitor | S -5 | 14.4 8.2 22.7 | 26 | 13d 19h 48m 02s |
ipsengine 569 | 413 ipsmonitor | S -5 | 14.8 7.8 22.7 | 32 | 13d 19h 48m 02s |
ipsengine 573 | 413 ipsmonitor | S -5 | 12.2 10.4 22.7 | 13 | 13d 19h 48m 02s |
ipsengine 555 | 413 ipsmonitor | S -5 | 14.4 8.0 22.5 | 5 | 13d 19h 48m 02s |
ipsengine 551 | 413 ipsmonitor | R -5 | 12.4 9.8 22.3 | 27 | 13d 19h 48m 02s |
ipsengine 567 | 413 ipsmonitor | S -5 | 13.8 8.4 22.3 | 37 | 13d 19h 48m 02s |
ipsengine 576 | 413 ipsmonitor | R -5 | 12.8 9.4 22.3 | 24 | 13d 19h 48m 02s |
ipsengine 549 | 413 ipsmonitor | R -5 | 12.0 10.0 22.1 | 11 | 13d 19h 48m 02s |
ipsengine 550 | 413 ipsmonitor | S -5 | 14.4 7.6 22.1 | 19 | 13d 19h 48m 02s |
ipsengine 571 | 413 ipsmonitor | S -5 | 12.2 9.8 22.1 | 1 | 13d 19h 48m 02s |
ipsengine 577 | 413 ipsmonitor | S -5 | 14.8 7.0 21.9 | 33 | 13d 19h 48m 02s |
ipsengine 560 | 413 ipsmonitor | S -5 | 13.6 7.8 21.5 | 30 | 13d 19h 48m 02s |
ipsengine 562 | 413 ipsmonitor | R -5 | 13.4 8.0 21.5 | 38 | 13d 19h 48m 02s |
ipsengine 572 | 413 ipsmonitor | R -5 | 13.0 7.4 20.5 | 36 | 13d 19h 48m 02s |
ipsengine 558 | 413 ipsmonitor | R -5 | 12.4 7.8 20.3 | 18 | 13d 19h 48m 02s |
-------------------------|--------------------------|---------|----------------------------|------|------------------|
+ 0 sshd processes | 0.0 0.0 0.0 |
+ 0 newcli processes | 0.0 0.0 0.0 |
+ 0 other processes | 0.0 0.0 0.0 |
summary | 477.8 292.8 770.6 |
inttop
There is no CLI command to calculate interrupt hits on FortiGate so the first pair of outputs rather shows the reported
CPU utilization from flhcli inttop matches the CPU utilization for the same core reported by diagnose sys mpstat.
The second pair of outputs show that running the interrupt list manually and substracting and dividing the counters
give approximately the same result as is shown in RUNS column of flhcli utility. The small difference is caused by
inaccurate timing when exiting the command on the FortiGate CLI twice with 5 seconds pause.
To validate time precision when collecting interrupt data, softirq timer can be used because it ticks 100 times per
second in FortiOS. This is what the last output shows. For some reason (?) the hardware interrupt LOC timer does
not tick 100 times per second on FortiOS any more but it looks variable.
FGT37D-2 # diagnose sys mpstat 5
TIME CPU %usr %nice %sys %iowait %irq %soft %steal %idle
12:29:12 AM all 11.21 0.00 7.58 0.00 0.00 9.12 0.00 72.08
0 0.00 0.00 2.37 0.00 0.20 0.20 0.00 97.23
1 10.87 0.00 8.89 0.00 0.00 0.00 0.00 80.24
2 0.00 0.00 1.38 0.00 0.00 0.00 0.00 98.62
3 13.64 0.00 12.85 0.00 0.00 0.00 0.00 73.52
4 0.00 0.00 0.99 0.00 0.00 0.00 0.00 99.01
5 14.03 0.00 7.91 0.00 0.00 0.00 0.00 78.06
6 0.00 0.00 2.37 0.00 0.00 0.00 0.00 97.63
7 13.64 0.00 9.29 0.00 0.00 0.00 0.00 77.08
8 13.64 0.00 9.09 0.00 0.00 0.00 0.00 77.27
9 14.03 0.00 7.11 0.00 0.00 0.00 0.00 78.85
10 15.02 0.00 11.07 0.00 0.00 0.00 0.00 73.91
11 14.03 0.00 7.91 0.00 0.00 0.00 0.00 78.06
12 15.22 0.00 8.89 0.00 0.00 0.20 0.00 75.69
13 16.80 0.00 9.88 0.00 0.00 0.00 0.00 73.32
14 13.24 0.00 7.51 0.00 0.00 0.00 0.00 79.25
15 10.87 0.00 8.50 0.00 0.00 0.00 0.00 80.63
16 15.42 0.00 10.47 0.00 0.00 0.00 0.00 74.11
17 12.65 0.00 9.29 0.00 0.00 0.00 0.00 78.06
18 10.28 0.00 6.92 0.00 0.00 0.00 0.00 82.81
19 13.04 0.00 8.10 0.00 0.00 0.00 0.00 78.85
20 0.00 0.00 0.99 0.00 0.00 95.45 0.00 3.56
21 0.00 0.00 0.00 0.00 0.00 92.89 0.00 7.11
22 0.00 0.00 0.99 0.00 0.00 88.14 0.00 10.87
23 0.00 0.00 0.00 0.00 0.00 87.94 0.00 12.06
24 11.07 0.00 7.31 0.00 0.00 0.00 0.00 81.62
25 28.26 0.00 14.62 0.00 0.00 0.00 0.00 57.11
26 15.02 0.00 12.25 0.00 0.00 0.00 0.00 72.73
27 11.07 0.00 8.10 0.00 0.00 0.00 0.00 80.83
28 29.25 0.00 14.03 0.00 0.00 0.00 0.00 56.72
29 13.83 0.00 7.51 0.00 0.00 0.00 0.00 78.66
30 12.25 0.00 10.47 0.00 0.00 0.00 0.00 77.27
31 13.24 0.00 8.30 0.00 0.00 0.00 0.00 78.46
32 14.03 0.00 10.47 0.00 0.00 0.00 0.00 75.49
33 12.85 0.00 6.92 0.00 0.00 0.00 0.00 80.24
34 13.44 0.00 7.91 0.00 0.00 0.00 0.00 78.66
35 10.47 0.00 9.68 0.00 0.00 0.00 0.00 79.84
36 11.07 0.00 7.31 0.00 0.00 0.00 0.00 81.62
37 11.86 0.00 7.91 0.00 0.00 0.00 0.00 80.24
38 12.45 0.00 8.50 0.00 0.00 0.00 0.00 79.05
39 11.86 0.00 9.09 0.00 0.00 0.00 0.00 79.05
flhcli inttop
LINE SOURCE CPU RUNS DESCRIPTION USR SYS NCE IRQ SWI IOW STL IDL
428 H 20 165027 np6_3-nturbo-tx-rx3 0 1 0 0 95 0 0 3
427 H 21 162951 np6_3-nturbo-tx-rx2 0 0 0 0 93 0 0 6
387 H 22 154028 np6_3-nturbo-tx-rx1 0 1 0 0 88 0 0 9
386 H 23 153920 np6_3-nturbo-tx-rx0 0 0 0 0 87 0 0 12
346 H 20 73954 np6_2-nturbo-tx-rx3 0 1 0 0 95 0 0 3
304 H 23 73108 np6_2-nturbo-tx-rx0 0 0 0 0 87 0 0 12
345 H 21 72737 np6_2-nturbo-tx-rx2 0 0 0 0 93 0 0 6
305 H 22 72481 np6_2-nturbo-tx-rx1 0 1 0 0 88 0 0 9
NET_RX S 22 68304 Network packets processing 0 1 0 0 88 0 0 9
NET_RX S 23 62301 Network packets processing 0 0 0 0 87 0 0 12
NET_RX S 21 55441 Network packets processing 0 0 0 0 93 0 0 6
NET_RX S 20 53858 Network packets processing 0 1 0 0 95 0 0 3
197 H 28 26633 np6_0-nturbo-ips-29 28 14 0 0 0 0 0 57
188 H 25 23554 np6_0-nturbo-ips-20 27 14 0 0 0 0 0 58
143 H 7 21237 np6_0-nturbo-ips-0 14 8 0 0 0 0 0 77
193 H 8 20559 np6_0-nturbo-ips-25 13 8 0 0 0 0 0 77
FGT37D-2 # diagnose hardware sysinfo interrupts | grep np6_3-nturbo-tx-rx3
diagnose hardware sysinfo interrupts | grep np6_3-nturbo-tx-rx3
CPU0 CPU1 CPU2 CPU3 CPU4 CPU5 CPU6 CPU7 CPU8 CPU9 CPU10 CPU11 CPU12 CPU13 CPU14 CPU15 CPU16 CPU17 CPU18 CPU19 CPU20 CPU21 CPU22 CPU23 CPU24 CPU25 CPU26 CPU27 CPU28 CPU29 CPU30 CPU31 CPU32 CPU33 CPU34 CPU35 CPU36 CPU37 CPU38 CPU39
428: 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 769066319 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 PCI-MSI-edge np6_3-nturbo-tx-rx3
... approximate and manual 5 seconds pause...
diagnose hardware sysinfo interrupts | grep np6_3-nturbo-tx-rx3
CPU0 CPU1 CPU2 CPU3 CPU4 CPU5 CPU6 CPU7 CPU8 CPU9 CPU10 CPU11 CPU12 CPU13 CPU14 CPU15 CPU16 CPU17 CPU18 CPU19 CPU20 CPU21 CPU22 CPU23 CPU24 CPU25 CPU26 CPU27 CPU28 CPU29 CPU30 CPU31 CPU32 CPU33 CPU34 CPU35 CPU36 CPU37 CPU38 CPU39
428: 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 769911634 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 PCI-MSI-edge np6_3-nturbo-tx-rx3
flhcli -2 inttop --desc np6_3-nturbo-tx-rx3
LINE SOURCE CPU RUNS DESCRIPTION USR SYS NCE IRQ SWI IOW STL IDL
428 H 20 165195 np6_3-nturbo-tx-rx3 0 0 0 0 95 0 0 4
flhcli -2 inttop --desc 'Normal timer' --no-hard
LINE SOURCE CPU RUNS DESCRIPTION USR SYS NCE IRQ SWI IOW STL IDL
TIMER S 33 100 Normal timer 12 6 0 0 0 0 0 81
TIMER S 5 100 Normal timer 13 10 0 0 0 0 0 76
TIMER S 4 100 Normal timer 0 3 0 0 0 0 0 96
TIMER S 3 100 Normal timer 14 10 0 0 0 0 0 75
TIMER S 2 100 Normal timer 0 1 0 0 0 0 0 99
TIMER S 1 100 Normal timer 14 10 0 0 0 0 0 75
TIMER S 0 100 Normal timer 0 0 0 0 0 0 0 99
TIMER S 11 100 Normal timer 11 7 0 0 0 0 0 81
TIMER S 13 100 Normal timer 11 8 0 0 0 0 0 80
TIMER S 14 100 Normal timer 12 8 0 0 0 0 0 80
TIMER S 15 100 Normal timer 14 8 0 0 0 0 0 78
TIMER S 16 100 Normal timer 12 9 0 0 0 0 0 78
TIMER S 17 100 Normal timer 12 8 0 0 0 0 0 79
TIMER S 18 100 Normal timer 15 8 0 0 0 0 0 76
TIMER S 19 100 Normal timer 10 8 0 0 0 0 0 82
TIMER S 27 100 Normal timer 14 7 0 0 0 0 0 78
TIMER S 21 100 Normal timer 0 0 0 0 92 0 0 7
TIMER S 22 100 Normal timer 0 0 0 0 89 0 0 11
TIMER S 23 100 Normal timer 0 0 0 0 88 0 0 12
TIMER S 24 100 Normal timer 16 7 0 0 0 0 0 77
TIMER S 25 100 Normal timer 26 12 0 0 0 0 0 60
TIMER S 26 100 Normal timer 10 9 0 0 0 0 0 80
TIMER S 28 100 Normal timer 29 12 0 0 0 0 0 57
TIMER S 29 100 Normal timer 13 10 0 0 0 0 0 76
TIMER S 30 100 Normal timer 12 7 0 0 0 0 0 80
TIMER S 31 100 Normal timer 14 6 0 0 0 0 0 78
TIMER S 32 100 Normal timer 11 6 0 0 0 0 0 82
TIMER S 34 100 Normal timer 12 7 0 0 0 0 0 80
TIMER S 10 100 Normal timer 10 7 0 0 0 0 0 81
TIMER S 6 100 Normal timer 0 1 0 0 0 0 0 98
interfaces
It this test it can be seen that the data rate reported by FortiTester includes the L1 overhead (ethernet preamble, start-of-frame and inter-packet gap), which might be confusing especially for small packets.
Normal data rate reported by interface counters on FortiGate (and also by get system performance status CLI command
on line Average network usage) does not include this overhead, therefore the data rate column of interfaces
command in flhcli does not match the FortiTester statistics. However, when the phy layer overhead and data rate summary
columns are added with -a ("advanced") parameter, it can be clearly seen that now both systems report the same speed.
Regarding the packet counts, the numbers from FortiTester and flhcli more or less matches (with small difference), caused by the inaccuracy in time when collecting the counters.
FortiTester generates UDP stream of 130 byte long packets
| ISF RX packets/s phy layer data rate % |...
INTERFACE D/SPEED | #ucast #bcast #mcast #errs data rate + overhead = summary util |...
--------------------------|--------------------------------------------------------------------------------------------|...
port6 F/10G | 0 0 0 0 736 bps 0 bps 736 bps 0 |...
port15 F/10G | 2,085,619 0 0 0 2.17 Gbps 333.70 Mbps 2.50 Gbps 25 |...
..........................| ISF TX packets/s phy layer data rate % |
..........................| #u+b+m #errs data rate + overhead = summary util |
..........................|----------------------------------------------------------------------|
..........................| 2,086,542 0 2.17 Gbps 333.85 Mbps 2.50 Gbps 25 |
..........................| 0 0 0 bps 0 bps 0 bps 0 |
FortiTester generates UDP stream of 1400 byte long packets
| ISF RX packets/s phy layer data rate % |...
INTERFACE D/SPEED | #ucast #bcast #mcast #errs data rate + overhead = summary util |...
--------------------------|--------------------------------------------------------------------------------------------|...
port6 F/10G | 0 0 0 0 1.09 Kbps 0 bps 1.09 Kbps 0 |...
port15 F/10G | 220,105 0 0 0 2.47 Gbps 35.22 Mbps 2.50 Gbps 25 |...
..........................| ISF TX packets/s phy layer data rate % |
..........................| #u+b+m #errs data rate + overhead = summary util |
..........................|----------------------------------------------------------------------|
..........................| 220,074 0 2.46 Gbps 35.21 Mbps 2.50 Gbps 25 |
..........................| 0 0 0 bps 0 bps 0 bps 0 |
FortiTester generates UDP stream of 130 byte long packets with 2.5 throughput towards 1G interface
As can be seen in following outputs, the L1 overhead is generally not calculated in FortiGate CLI outputs. That is the
reason why in following example FortiGate reports only about 876 Mbps in get system performance status command, but
in reality FortiTester is generating 2 Gbps, which completely fills the 1 Gbps interface on FortiGate. When L1 overhead
is calculated (which makes about 133 Mbps for this amount of small packets) we get the 1 Gbps througput.
This also shows that the data rate column in flhcli matches the Average network usage line calculated by FortiGate.
| ISF RX packets/s phy layer data rate % |
INTERFACE D/SPEED | #ucast #bcast #mcast #errs data rate + overhead = summary util |
--------------------------|--------------------------------------------------------------------------------------------|
port1 F/1G | 833,894 0 0 0 867.25 Mbps 133.42 Mbps 1.00 Gbps 100 |
FG3H0E-3 # get system performance status | grep 'Average network usage'
Average network usage: 867915 / 867910 kbps in 1 minute, ...
np6lanes
NP6 lanes counter directly match interfaces counters only if there is not ISF. In case of ISF there are 4 bytes added when forwarding packet from ISF to NP6 XAUI, which can make a noticable difference for a lot of small packets.
This can also cause the packets dropped on ISF (such are not shown in NP6 drop counters) because
the front port can receive data on its link speed but there might not be enough space to add 4B
for all incoming packets, resulting in errors on outgoing XAUI (which can be displayed with
interfaces command using parameters --no-isf-tx --show-xaui-rx - those were also used to
collect following screenshots).
Just on the edge - last throughput with no errors
It is clearly seen that FortiTester receives exactly the same traffic that it generated (which is 9738 Mbps):
The same amount of traffic is displayed in interfaces command for ISF RX. However XAUI TX
for this traffic is noticably higher (by about 260 Mbps). With 8119498 incoming packets per second,
4 bytes added to each packet makes almost exactly 260 Mbps.
In the np6lanes output it can be seen that data rate, overhead and summary matches to what was
reported in XAUI TX in interfaces command. Since these two counters are completely independent
it confirms the np6lanes command works well.
Over the edge - errors starting
In this output it can be seen that just a small addion to the thoughput start generating errors
in interfaces utility in XAUI RX #errs column.
In FortiTester statistics it is clear that some generated traffic is not received any more (9749 Mbps sent, 9740 Mbps received).
Notice the error counter in XAUI RX #errs
And output from np6lanes
This also confirms that the data rate reported by NP6 XAUI couters do not include the overhead -
on the last screenshot the reported data rate on XAUI is only 8.73 Gbps, but ISF is already reporting
errors. When adding also the L1 overhead of 1.3 Gbps, we see that the summary is slightly over 10 Gbps.
Important thing here is that XAUI which is overloaded on incoming does not raise any of its drop counters. This is because the traffic if already dropped by ISF and capacity of XAUI link between ISF and NP6 is never exceeded.