《NetBSD指南-18.7.2.kgmon输出的解释》

[leo]

现在可以运行kgmon来收集和分析信息, 现在是我们看看这些信息的时候了。在这个特定的例子中,
一个 GENERIC 内核运行了大约一个小时左右，而且开启了分析(profiling)，只有系统进程没有不
利的额外负载, 而如果内核中有代码缺陷, 即使在最小的系统负载下可能系统资源的占用也很大，
这相对来说更容易诊断出问题所在。

18.7.2.1. 简约报告
flat profile(简约报告或简约分析)是一个函数列表, 描述了函数被调用的次数和调用的时间(以秒
计). 下面的示例是一个很空闲的系统的输出:

Flat profile:

代码: 全选

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ns/call  ns/call  name
 99.77    163.87   163.87                             idle
  0.03    163.92     0.05      219 228310.50 228354.34  _wdc_ata_bio_start
  0.02    163.96     0.04      219 182648.40 391184.96  wdc_ata_bio_intr
  0.01    163.98     0.02     3412  5861.66  6463.02  pmap_enter
  0.01    164.00     0.02      548 36496.35 36496.35  pmap_zero_page
  0.01    164.02     0.02                             Xspllower
  0.01    164.03     0.01   481968    20.75    20.75  gettick
  0.01    164.04     0.01     6695  1493.65  1493.65  VOP_LOCK
  0.01    164.05     0.01     3251  3075.98 21013.45  syscall_plain
...

不出所料, idle 有很高的百分比, 但是, 还有些事情值得我们注意, 例如再往下看，有个 vn_lock 函数:

代码: 全选

...
  0.00    164.14     0.00     6711     0.00     0.00  VOP_UNLOCK
  0.00    164.14     0.00     6677     0.00  1493.65  vn_lock
  0.00    164.14     0.00     6441     0.00     0.00  genfs_unlock

这不意外, 因为不管怎样加锁是必需的。

18.7.2.2. 调用图形报告
调用图形是一个简约报告的扩展版本显示了后来列表中函数的调用。 首先看这个输出示例:

代码: 全选

                     Call graph (explanation follows)


granularity: each sample hit covers 4 byte(s) for 0.01% of 164.14 seconds

index % time    self  children    called     name
                                                 <spontaneous>
[1]     99.8  163.87    0.00                 idle [1]
-----------------------------------------------
                                                 <spontaneous>
[2]      0.1    0.01    0.08                 syscall1 [2]
                0.01    0.06    3251/3251        syscall_plain [7]
                0.00    0.01     414/1660        trap [9]
-----------------------------------------------
                0.00    0.09     219/219         Xintr14 [6]
[3]      0.1    0.00    0.09     219         pciide_compat_intr [3]
                0.00    0.09     219/219         wdcintr [5]
-----------------------------------------------
...

现在读者可能有些迷惑. 行尾的尾号被映射到前面的索引号码, 例如,

代码: 全选

...
                0.00    0.01      85/85          dofilewrite [68]
[72]     0.0    0.00    0.01      85         soo_write [72]
                0.00    0.01      85/89          sosend [71]
...

这里我们看见dofilewrite先被调用, 现在我们看索引号码为64这段，看看这里发生了什么:

代码: 全选

...
                0.00    0.01     101/103         ffs_full_fsync <cycle 6> [58]
[64]     0.0    0.00    0.01     103         bawrite [64]
                0.00    0.01     103/105         VOP_BWRITE [60]
...

其余依此类推, 可以建立一个"可视化的追踪".

在调用图形的最后，当好在terms区域的后面是一个函数名称索引，它同样可以帮助映射索引.