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

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)