《NetBSD指南-18.7.3.利用》

[leo]

本例中, 我修改了内核的一个区域，我知道会产生明显的问题.

这是在系统运行了大约一个小时后，加上用户的少许配合，生成的一个简约报告的开始部分:

代码: 全选

Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls  us/call  us/call  name
 93.97    139.13   139.13                             idle
  5.87    147.82     8.69       23 377826.09 377842.52  check_exec
  0.01    147.84     0.02      243    82.30    82.30  pmap_copy_page
  0.01    147.86     0.02      131   152.67   152.67  _wdc_ata_bio_start
  0.01    147.88     0.02      131   152.67   271.85  wdc_ata_bio_intr
  0.01    147.89     0.01     4428     2.26     2.66  uvn_findpage
  0.01    147.90     0.01     4145     2.41     2.41  uvm_pageactivate
  0.01    147.91     0.01     2473     4.04  3532.40  syscall_plain
  0.01    147.92     0.01     1717     5.82     5.82  i486_copyout
  0.01    147.93     0.01     1430     6.99    56.52  uvm_fault
  0.01    147.94     0.01     1309     7.64     7.64  pool_get
  0.01    147.95     0.01      673    14.86    38.43  genfs_getpages
  0.01    147.96     0.01      498    20.08    20.08  pmap_zero_page
  0.01    147.97     0.01      219    45.66    46.28  uvm_unmap_remove
  0.01    147.98     0.01      111    90.09    90.09  selscan
...

很明显, 性能上有极大的区别。 马上idle time就显著地减小了. 这里最显著的区别是相比全局其它的函数，一个特殊的函数有很高的time值，但是调用次数很少。这个函数是 check_exec. 刚开始, 如果有很多命令在运行这可能看起来不太奇怪, 但是和前面第一次测量生成的简约报告对比, 相应地看起来就不太对劲了:

代码: 全选

...
  0.00    164.14     0.00       37     0.00 62747.49  check_exec
...

第一次测量时调用为37次，而且有很好的性能。 很显然这个函数里或围绕它的某些项有问题。 要排除其它的函数, 看一下调用图形会有帮助, 这里第一个示例中的 check_exec

代码: 全选

...
-----------------------------------------------
                0.00    8.69      23/23          syscall_plain [3]
[4]      5.9    0.00    8.69      23         sys_execve [4]
                8.69    0.00      23/23          check_exec [5]
                0.00    0.00      20/20          elf32_copyargs [67]
...[code]
注意 time值为8.69 这个函数是怎样影响前面的两个函数的。 它们之中有地方出问题了, 但是, 后面的例子中 check_exec 看起来似乎不同:

...
-----------------------------------------------
8.69 0.00 23/23 sys_execve [4]
[5] 5.9 8.69 0.00 23 check_exec [5]
...
现在我们找到这个问题所在了, 很有可能就在 check_exec 里. 当然了, 问题不可能总是如此简单，而事实上, 这里有一个"傻瓜"代码正好被插入到 check_exec (这个函数在 sys/kern/kern_exec.c)后面:

...
/* A Cheap fault insertion */
for (x = 0; x < 100000000; x++) {
y = x;
}
..
[/code]
并不起眼, 但是足以在分析报告中产生很大的变化。