Subject: large idle time during ipsec
To: None <tech-net@netbsd.org>
From: Adolf Hohl <adolf.hohl@security.kpnqwest.com>
List: tech-net
Date: 08/10/2000 11:28:39
Hi,
i was interested in time consumption of some kern procedures processing IP
and handle network io. I made a kernel profile and noticed that the cpu is
nearly idle half the time during ipsec-processing.
My environment looks like this:
host-----ipsec-gate---------ipsec-gate------host
3des,tunnel-mode,esp
1.5_ALPHA is running on all machines. The gateways are P3/450 with 2 or 3
3C905-100Mbit interfaces (no pci-interrupt sharing). Hosts are Celeron 500
with same interfaces.
I made kernel profiles on the right gateway. I produced load on the net by
pinging from host to host with the -f option. After that i used different
icmp packet sizes ( -s 2000, 4000, 8000).
With ping-f the cpu has 18 % idle, with ping -f -s 2000 the cpu has 60 % idle
time. With sizes of 4000 and 8000 bytes the cpu is only 45 % idle.
I don't know where the bottleneck is. I supposed that the kern is out of mbufs,
but no console message appeared.
Does anybody know more?
Here's a short output of gprof.
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls us/call us/call name
46.35 642.83 642.83 idle
26.70 1013.23 370.40 298030802 1.24 1.24 des_encrypt
4.55 1076.36 63.13 1302430 48.47 332.86 des_cbc_encrypt
2.61 1112.58 36.22 7916541 4.58 8.05 ex_intr
2.39 1145.68 33.10 Xspllower
1.94 1172.53 26.85 Xintr10
1.55 1194.03 21.50 4506991 4.77 4.77 crc32_a
1.36 1212.94 18.91 Xdoreti
0.65 1221.99 9.05 3935768 2.30 3.98 ex_start
0.61 1230.52 8.53 17189287 0.50 0.50 _pool_get
0.52 1237.69 7.17 17189264 0.42 0.42 _pool_put
0.48 1244.38 6.69 5158206 1.30 107.69 ip_input
0.44 1250.47 6.09 3792472 1.61 73.67 ip_output
0.41 1256.13 5.66 7584944 0.75 0.75 ipsec_setspidx_mbuf
0.40 1261.61 5.48 1305894 4.20 4.20 microtime
0.38 1266.83 5.22 1302430 4.01 4.01 des_set_key
0.37 1272.01 5.18 4506736 1.15 5.01 ether_output
0.36 1276.98 4.97 7584944 0.66 2.07 ipsec4_getpolicybyaddr
0.30 1281.10 4.12 4507043 0.91 2.52 ex_add_rxbuf
0.28 1284.94 3.84 16331290 0.24 0.41 _bus_dmamap_load_buffer
0.27 1288.67 3.73 3792574 0.98 1.04 rn_match
0.26 1292.26 3.58 loop_128
0.26 1295.83 3.57 3792472 0.94 78.59 icmp_input
0.23 1299.01 3.18 4507043 0.71 1.13 ether_input
0.20 1301.81 2.80 15480051 0.18 0.18 pmap_extract
0.18 1304.36 2.55 7584944 0.34 0.67 key_allocsp
0.18 1306.88 2.52 3792472 0.66 74.79 icmp_reflect
0.17 1309.18 2.31 4507047 0.51 2.02 m_freem
0.14 1311.08 1.89 651215 2.90 348.89 esp4_input
0.13 1312.91 1.84 651215 2.83 347.56 esp_output
0.13 1314.72 1.81 3792472 0.48 0.66 key_cmpspidx_withmask
0.13 1316.52 1.79 4506728 0.40 1.46 _bus_dmamap_load_mbuf
0.11 1318.06 1.54 651215 2.36 355.43 ipsec4_output
0.10 1319.51 1.45 4428150 0.33 125.78 ipintr
0.10 1320.86 1.35 5952325 0.23 0.23 m_adj
0.09 1322.12 1.26 3141257 0.40 0.92 m_prepend
0.08 1323.28 1.16 3792609 0.31 0.31 in_broadcast
0.08 1324.42 1.15 Xsoftnet
0.08 1325.56 1.14 finished_8
0.08 1326.66 1.10 4506734 0.24 0.38 arpresolve