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