Subject: Some profiling data
To: None <port-pmax@netbsd.org>
From: Ken Wellsch <kwellsch@tampabay.rr.com>
List: port-pmax
Date: 01/31/2001 12:56:30
I believe doing some kernel profiling was suggested as a way to aid in
determining why the slow-down in performance reported by a few folks.
So without any guidelines, I have done this:
On a 5k/150 system installed with 1.5 ISO I dumped the ftp.netbsd.org
based -current tar_files src circa Saturday Jan 27th with the mklocale
fix applied. I built & installed that.
>From the -current system I compiled a profiling kernel and after booting
with that, did a "make build" with profiling enabled.
Here are the results (no idle time really - I started the build immediately
via a networked ssh connection and collected this output upon completion):
12:35PM up 1 day, 3:14, 1 user, load averages: 1.16, 1.83, 2.15
NetBSD 1.5R (PMAX50.PROF) #0: Tue Jan 30 09:01:04 EST 2001
DECstation 5000/150 (3MIN)
total memory = 128 MB
Source January 27th tar balls + mklocale patch. Result from "make build"
Each sample counts as 0.00390625 seconds.
% cumulative self self total
time seconds seconds calls us/call us/call name
6.99 1191.31 1191.31 47987163 24.83 24.83 mips3_FlushDCache
6.05 2222.80 1031.50 366480784 2.81 2.81 lockmgr
5.80 3211.00 988.20 __mcount
5.64 4172.96 961.95 memmove
4.49 4938.19 765.23 _mcount
3.98 5617.22 679.03 33731875 20.13 115.72 uvm_fault
3.71 6249.89 632.67 293080 2158.69 2158.69 mips_idle
3.01 6762.63 512.74 19260441 26.62 26.62 mips3_FlushICache
2.80 7239.22 476.59 10552552 45.16 470.48 lookup
2.57 7676.58 437.36 1379566 317.03 317.03 mips_pagecopy
2.54 8110.41 433.83 71665592 6.05 15.51 cache_lookup
2.38 8516.08 405.67 35664451 11.37 26.69 pmap_enter
2.21 8893.18 377.09 33533496 11.25 125.70 trap
1.80 9199.46 306.28 34173035 8.96 43.88 pmap_remove_pv
1.60 9472.82 273.36 _splraise_noprof
1.47 9724.11 251.30 38803025 6.48 6.48 pmap_remove
1.43 9967.75 243.64 11632014 20.95 20.95 mips_pagezero
1.41 10208.21 240.46 71665592 3.36 22.65 ufs_lookup
1.39 10444.99 236.78 36862050 6.42 217.43 syscall_plain
1.38 10680.62 235.63 48826370 4.83 4.86 _pool_get
1.21 10886.19 205.57 21587101 9.52 16.40 uvn_findpages
1.16 11084.41 198.22 22503131 8.81 8.81 memset
1.11 11273.14 188.73 34467512 5.48 5.64 uvm_pagelookup
0.97 11439.17 166.03 181136956 0.92 0.92 pmap_extract
...
0.00 17050.91 0.00 1 0.00 0.00 unp_setpeeraddr
0.00 17050.91 0.00 1 0.00 0.00 vfinddev
0.00 17050.91 0.00 1 0.00 0.00 vgone
I can provide the full output if anyone would like it...
Cheers,
-- Ken Wellsch