Subject: Re: Some kernel profiling on a 5000/133 with -current
To: port-pmax <port-pmax@netbsd.org>
From: Ken Wellsch <kwellsch@tampabay.rr.com>
List: port-pmax
Date: 08/31/2001 13:59:14
So that I am not labeled bonnie-centric, here is some profile
data produced using ttcp for network I/O activity.
I ran ttcp 20 times for each of TCP/transmit, TCP/receive and
UDP/transmit. Alas UDP/receive could not keep up with the
NetBSD/i386 box I was using, so I gave up on that test.
Because I had to delay to make sure sender/rcver would synchronize,
I'd just ignore the mips_idle profile stats.
ttcp run, TCP receiving. Default 16Mb transfer. 20 serial invocations.
% cumulative self self total
time seconds seconds calls us/call us/call name
38.62 175.95 175.95 _splset_noprof
25.32 291.30 115.35 1724282 66.90 72.19 ioasic_attach_devs
13.10 350.99 59.68 645 92532.70 92532.70 mips_idle
5.13 374.38 23.39 1115997 20.96 23.86 memcpy
2.95 387.83 13.45 _mcount
2.65 399.88 12.05 __mcount
2.16 409.72 9.84 382124 25.75 130.51 ifconf
1.14 414.91 5.19 232045 22.37 582.01 am7990_intr
1.12 420.02 5.10 150987 33.79 238.30 tcp_output
0.88 424.04 4.02 231830 17.36 220.78 lance_read
memcpy data profile:
308 aligned [0-2)
0 aligned [2-4)
152986 20.9% aligned [4-8)
152218 20.8% aligned [8-16)
4315 aligned [16-32)
153696 21.0% aligned [32-64)
6263 aligned [64-128)
3206 aligned [128-256)
16148 aligned [256-512)
29321 aligned [512-1024)
213972 29.2% aligned [1024-2048)
16 aligned [2048-4096)
43 aligned [4096-8192)
0 aligned [8192-16384)
732492 65.6% aligned memcpy
928 unaligned [0-2)
150356 39.2% unaligned [2-4)
169 unaligned [4-8)
231878 60.5% unaligned [8-16)
20 unaligned [16-32)
95 unaligned [32-64)
0 unaligned [64-128)
0 unaligned [128-256)
15 unaligned [256-512)
0 unaligned [512-1024)
0 unaligned [1024-2048)
0 unaligned [2048-4096)
0 unaligned [4096-8192)
0 unaligned [8192-16384)
383461 34.4% unaligned memcpy
1115997 100.0% memcpy
ttcp run, TCP transmitting. Default 16Mb transfer. 20 serial invocations.
% cumulative self self total
time seconds seconds calls us/call us/call name
38.88 183.68 183.68 _splset_noprof
15.61 257.41 73.73 1666015 44.26 50.43 memcpy
5.41 282.98 25.57 320182 79.86 398.18 tcp_output
4.70 305.21 22.23 _mcount
4.53 326.62 21.42 102 209980.09 209980.09 mips_idle
4.38 347.32 20.70 __mcount
4.17 367.03 19.70 389473 50.59 80.83 ifconf
3.45 383.30 16.28 389466 41.79 41.80 in4_cksum
1.83 391.96 8.65 2123563 4.07 13.32 ioasic_attach_devs
1.67 399.86 7.91 1275205 6.20 7.10 memc_aligned
1.36 406.31 6.45 352680 18.28 151.53 am7990_intr
1.09 411.46 5.15 234171 22.00 205.90 ip_output
memcpy data profile:
281 aligned [0-2)
0 aligned [2-4)
237644 18.6% aligned [4-8)
237595 18.6% aligned [8-16)
8730 aligned [16-32)
241104 18.9% aligned [32-64)
15031 aligned [64-128)
32211 aligned [128-256)
58432 aligned [256-512)
116082 9.1% aligned [512-1024)
164354 12.9% aligned [1024-2048)
163698 12.8% aligned [2048-4096)
43 aligned [4096-8192)
0 aligned [8192-16384)
1275205 76.5% aligned memcpy
842 unaligned [0-2)
157913 40.4% unaligned [2-4)
198 unaligned [4-8)
231649 59.3% unaligned [8-16)
67 unaligned [16-32)
81 unaligned [32-64)
0 unaligned [64-128)
0 unaligned [128-256)
20 unaligned [256-512)
0 unaligned [512-1024)
0 unaligned [1024-2048)
0 unaligned [2048-4096)
0 unaligned [4096-8192)
0 unaligned [8192-16384)
390770 23.5% unaligned memcpy
1666015 100.0% memcpy
ttcp run, UDP transmitting. Default 16Mb transfer. 20 serial invocations.
% cumulative self self total
time seconds seconds calls us/call us/call name
28.72 88.20 88.20 _splset_noprof
14.25 131.97 43.77 1661591 26.34 29.20 memcpy
9.58 161.40 29.43 1714085 17.17 35.39 ioasic_attach_devs
8.82 188.48 27.08 585 46294.07 46294.07 mips_idle
6.35 207.98 19.50 _mcount
5.96 226.30 18.32 __mcount
5.48 243.14 16.84 41597 404.74 404.74 in4_cksum
2.94 252.18 9.04 41587 217.45 1359.03 ip_output
1.79 257.68 5.50 247214 22.23 87.72 ifconf
1.33 261.76 4.09 246629 16.57 278.19 am7990_intr
1.29 265.72 3.96 207295 19.09 26.75 m_dup
memcpy data profile:
0 aligned [0-2)
0 aligned [2-4)
251165 39.7% aligned [4-8)
85197 13.5% aligned [8-16)
45624 7.2% aligned [16-32)
208 aligned [32-64)
83470 13.2% aligned [64-128)
345 aligned [128-256)
787 aligned [256-512)
20 aligned [512-1024)
41477 6.6% aligned [1024-2048)
124387 19.7% aligned [2048-4096)
42 aligned [4096-8192)
0 aligned [8192-16384)
632722 38.1% aligned memcpy
0 unaligned [0-2)
370179 36.0% unaligned [2-4)
82309 8.0% unaligned [4-8)
576245 56.0% unaligned [8-16)
40 unaligned [16-32)
80 unaligned [32-64)
0 unaligned [64-128)
0 unaligned [128-256)
16 unaligned [256-512)
0 unaligned [512-1024)
0 unaligned [1024-2048)
0 unaligned [2048-4096)
0 unaligned [4096-8192)
0 unaligned [8192-16384)
1028869 61.9% unaligned memcpy
1661591 100.0% memcpy
Cheers,
-- Ken