奇怪探查行为：相同的功能，不同的表演

Question

我学习使用gprof的，然后我得到这个代码怪异的结果：

int one(int a, int b) 
{ 
    int i, r = 0; 
    for (i = 0; i < 1000; i++) 
    { 
     r += b/(a + 1); 
    } 
    return r; 
} 

int two(int a, int b) 
{ 
    int i, r = 0; 
    for (i = 0; i < 1000; i++) 
    { 
     r += b/(a + 1); 
    } 
    return r; 
} 

int main() 
{ 
    for (int i = 1; i < 50000; i++) 
    { 
     one(i, i * 2); 
     two(i, i * 2); 
    } 
    return 0; 
} 

，这是探查输出

% cumulative self    self  total   
time seconds seconds calls us/call us/call name  
50.67  1.14  1.14 49999 22.80 22.80 two(int, int) 
49.33  2.25  1.11 49999 22.20 22.20 one(int, int) 

如果我呼叫一个然后两个结果是相反的，两个需要更多的时间比一个
都是相同的功能，但第一个电话总是花费较少的时间，然后第二个

这是为什么？

注：汇编代码是完全一样的和代码正在与没有优化编译

Answer 1

我猜它是在运行时优化一些侥幸 - 一个使用寄存器和其他没有或像这样的小事。

系统时钟可能运行到100nsec的精度。平均通话时间30nsec或25nsec小于一个时钟周期。时钟周期的5％舍入误差相当小。两次都接近零。

Answer 2

它总是第一个被称为稍慢的？如果是这样的话，我会猜测这是一个CPU缓存做它的事情。或者它可能是操作系统的懒惰分页。

顺便说一句：哪些优化标志正在编译？

Answer 3

我的猜测：这是mcount数据被解释的方式的人为因素。 mcount（monitor.h）的粒度大小为32位长字 - 我的系统上有4个字节。所以你不会期待这个：在EXACT同一个mon.out文件中，我从prof vs gprof得到了不同的报告。 solaris 9 -

prof 
%Time Seconds Cumsecs #Calls msec/call Name 
    46.4 2.35 2.3559999998  0.0000 .div 
    34.8 1.76 4.11120000025  0.0000 _mcount 
    10.1 0.51 4.62  1 510.  main 
    5.3 0.27 4.8929999999  0.0000 one 
    3.4 0.17 5.0629999999  0.0000 two 
    0.0 0.00 5.06  1  0.  _fpsetsticky 
    0.0 0.00 5.06  1  0.  _exithandle 
    0.0 0.00 5.06  1  0.  _profil 
    0.0 0.00 5.06  20  0.0  _private_exit, _exit 
    0.0 0.00 5.06  1  0.  exit 
    0.0 0.00 5.06  4  0.  atexit 


gprof 
    % cumulative self    self total 
time seconds seconds calls ms/call ms/call name 
71.4  0.90  0.90  1 900.00 900.00 key_2_text  <cycle 3> [2] 
    5.6  0.97  0.07 106889  0.00  0.00 _findbuf [9] 
    4.8  1.03  0.06 209587  0.00  0.00 _findiop [11] 
    4.0  1.08  0.05       __do_global_dtors_aux [12] 
    2.4  1.11  0.03       mem_init [13] 
    1.6  1.13  0.02 102678  0.00  0.00 _doprnt [3] 
    1.6  1.15  0.02       one [14] 
    1.6  1.17  0.02       two [15] 
    0.8  1.18  0.01 414943  0.00  0.00 realloc <cycle 3> [16] 
    0.8  1.19  0.01 102680  0.00  0.00 _textdomain_u  <cycle 3> [21] 
    0.8  1.20  0.01 102677  0.00  0.00 get_mem [17] 
    0.8  1.21  0.01       $1 [18] 
    0.8  1.22  0.01       $2 [19] 
    0.8  1.23  0.01       _alloc_profil_buf [22] 
    0.8  1.24  0.01       _mcount (675)