Benchmark の取り方
なんか頼まれたし書いておくか。結論から言えば、迷って benchmark をとって、騙されていたら世話無いという。
とりあえず、Dan さんのコードをちょいと改造。
--- pow.c.orig 2007-12-14 17:58:05.000000000 +0900 +++ pow.c 2007-12-14 18:11:37.000000000 +0900 @@ -33,7 +33,7 @@ int main(int argc, char *argv[]){ U32 i, j; U64 rl, rn, rm; - double tl, tn, tm; + double tl, tn, tm, tc; for (i = 0; i < 40; i++) { tl = time_hires(); for (j = 0; j < REPEAT; j++) rl = uipower_o_logn(3, i); @@ -46,12 +46,16 @@ tm = time_hires(); for (j = 0; j < REPEAT; j++) rm = uipower_libm(3, i); tm = time_hires() - tm; + + tc = time_hires(); + for (j = 0; j < REPEAT; j++); + tc = time_hires() - tc; #if DEBUG - printf("uipower(3,%u)=%llu/%llu/%llu\t%.0f\t%.0f\t%0.f\n", - i, rl, rn, rm, tl*1e6, tn*1e6, tm*1e6); + printf("uipower(3,%u)=%llu/%llu/%llu\t%.0f\t%.0f\t%0.f\t%0.f\n", + i, rl, rn, rm, tl*1e6, tn*1e6, tm*1e6, tc*1e6); #else - printf("uipower(3,%u)=%llu\t%u\t%.0f\t%.0f\t%0.f\n", - i, rl, i, tl*1e6, tn*1e6, tm*1e6); + printf("%3u%10.f%10.f%10.f%10.f\n", + i, tl*1e6, tn*1e6, tm*1e6, tc*1e6); #endif } }
Mac OS 10.4.10 on Intel Core Duo 1.66 GHz、gcc 4.0.1 でコンパイル、実行してみる。
0 25299 21633 13656 13641 1 36927 41415 13648 13711 2 46134 53827 13713 13655 3 52352 67263 13675 13668 4 57956 84624 13680 13683 5 67033 93066 13677 13712 6 61490 106542 13683 13956 7 69833 122183 16418 16906 8 75655 133581 13693 13688 9 73111 146195 13692 14121 10 69205 160431 13658 13641 11 76185 173823 13680 13644 12 67288 184722 13714 13644 13 81014 197456 13655 13756 14 76162 211199 13723 13682 15 100299 223086 13768 13679 16 76664 234753 13644 13652 17 84088 249854 13666 13644 18 78413 265410 13647 13720 19 87427 276786 13687 13659 20 79266 294455 13663 13680 21 108081 303166 13659 13803 22 85217 317951 13753 13721 23 96077 329471 13693 13733 24 81573 345572 13645 16093 25 104336 357664 13702 13732 26 85176 371659 13755 13679 27 97371 385948 13831 13881 28 85312 392645 13724 13682 29 95794 407046 13675 14021 30 90668 421307 13634 13647 31 97893 432798 13640 13649 32 90453 449957 13654 15420 33 93790 461379 13650 13663 34 90483 482835 13739 13796 35 98941 490067 13696 13642 36 96891 508946 13676 13695 37 100228 521318 14460 13666 38 93947 528717 13689 13639 39 109367 546555 13676 13711
賢明な人ならこの時点で結論が出てますね。
分からないなら -pg を付けてコンパイルしてプロファイルをとった結果でも。
% gcc -O2 -g -pg pow.c -o pow % ./pow (snip) % gprof pow (snip) granularity: each sample hit covers 4 byte(s) for 0.12% of 8.45 seconds % cumulative self self total time seconds seconds calls ms/call ms/call name 61.3 5.18 5.18 40000000 0.00 0.00 _uipower_o_n [3] 15.7 6.50 1.32 40000000 0.00 0.00 _uipower_o_logn [4] 12.3 7.54 1.04 1 1040.00 7560.00 _main [1] 8.4 8.26 0.71 _moncount (2601) 1.7 8.39 0.14 mcount (27) 0.4 8.43 0.03 _monreset (2605) 0.2 8.44 0.01 320 0.05 0.05 _time_hires [5] 0.1 8.45 0.01 ___sinit [6] (snip)
念のためにアセンブリを見ても良い。
% gcc -O2 -S pow.c
% grep -F 'call' pow.s
call ___i686.get_pc_thunk.bx
call L_gettimeofday$stub
call ___i686.get_pc_thunk.bx
call L_pow$stub
call ___i686.get_pc_thunk.bx
call _time_hires
call _uipower_o_logn
call _time_hires
call _time_hires
call _uipower_o_n
call _time_hires
call _time_hires
call _time_hires
call _time_hires
call _time_hires
call L_printf$stubもちろん、インライン展開されたりしている訳ではない。
結論。最適化すると libm の pow が速くなるのではなく、単に最適化によって no effect(無意味) なコードが削除されただけ。というか、既にコンパイルされている共有ライブラリのコードが最適化で速くなるわけが無い*1。
自分もやったことがあるけど、最適化がされる場合に、benchmark をとるときは対象のコードが「実際に実行されているか」を確認しないと駄目。ローカル変数への代入くらいだとコンパイラは割と簡単に無意味であることを検知してしまうので、そのあたりを意識しないと無意味な benchmark になってしまう。
追記
いろいろ説明するのが面倒なのでコードとアセンブリを全部掲載しておく。なお、Darwin では -fno-math-errno がデフォルトなので Mac OS X 以外の人は -fno-math-errno をつけて実験すると良い。下のコードは gcc-4.2 on coLinux でコンパイルしてある。
#include <stdio.h> #include <math.h> #include <sys/time.h> #if !defined(REPEAT) #define REPEAT ((int) 1e6) #endif typedef unsigned int U32; typedef unsigned long long U64; double time_hires() { struct timeval now; gettimeofday(&now, NULL); return now.tv_sec + now.tv_usec / 1e6; } U64 uipower_o_logn(U64 b, U64 n) { U64 result = 1; for (; n != 0 ; b *= b, n >>= 1) if (n & 1) result *= b; return result; } U64 uipower_o_n(U64 b, U64 n) { U64 result = 1; for (; n != 0 ; n--) result *= b; return result; } U64 uipower_libm(U64 b, U64 n) { U64 result = pow(b, n); return result; } int main() { U32 i, j; U64 rl, rn, rm; double tl, tn, tm; for (i = 0; i < 40; i++) { tl = time_hires(); for (j = 0; j < REPEAT; j++) rl = uipower_o_logn(3, i); tl = time_hires() - tl; tn = time_hires(); for (j = 0; j < REPEAT; j++) rn = uipower_o_n(3, i); tn = time_hires() - tn; tm = time_hires(); for (j = 0; j < REPEAT; j++) rm = uipower_libm(3, i); tm = time_hires() - tm; #if DEBUG printf("uipower(3,%u)=%llu/%llu/%llu\t%.0f\t%.0f\t%0.f\n", i, rl, rn, rm, tl*1e6, tn*1e6, tm*1e6); #else printf("uipower(3,%u)=%llu\t%u\t%.0f\t%.0f\t%0.f\n", i, rl, i, tl*1e6, tn*1e6, tm*1e6); #endif } }
.file "pow.c" .text .p2align 4,,15 .globl uipower_o_logn .type uipower_o_logn, @function uipower_o_logn: pushl %ebp movl %esp, %ebp pushl %edi pushl %esi pushl %ebx subl $20, %esp movl 20(%ebp), %edi movl 16(%ebp), %esi movl 8(%ebp), %ecx movl 12(%ebp), %ebx movl %edi, %eax orl %esi, %eax movl $1, -24(%ebp) movl $0, -20(%ebp) jne .L4 jmp .L7 .p2align 4,,7 .L11: movl %ebx, %eax imull %ecx, %eax addl %eax, %eax movl %eax, -28(%ebp) movl %ecx, %eax mull %ecx movl %edx, %ebx movl %eax, %ecx addl -28(%ebp), %ebx .L4: movl %esi, %eax andl $1, %eax testl %eax, %eax je .L5 movl -20(%ebp), %edx movl -24(%ebp), %eax imull %ecx, %edx movl %edx, -28(%ebp) movl -24(%ebp), %edx imull %ebx, %edx addl %edx, -28(%ebp) mull %ecx movl %eax, -24(%ebp) movl -28(%ebp), %eax addl %eax, %edx movl %edx, -20(%ebp) .L5: shrdl $1, %edi, %esi shrl %edi movl %edi, %edx orl %esi, %edx jne .L11 .L7: movl -24(%ebp), %eax movl -20(%ebp), %edx addl $20, %esp popl %ebx popl %esi popl %edi popl %ebp ret .size uipower_o_logn, .-uipower_o_logn .p2align 4,,15 .globl uipower_o_n .type uipower_o_n, @function uipower_o_n: pushl %ebp movl %esp, %ebp pushl %edi pushl %esi pushl %ebx subl $20, %esp movl 20(%ebp), %ebx movl 16(%ebp), %ecx movl 8(%ebp), %esi movl 12(%ebp), %edi movl %ebx, %eax orl %ecx, %eax movl $1, -24(%ebp) movl $0, -20(%ebp) je .L15 .p2align 4,,7 .L16: movl -20(%ebp), %edx movl -24(%ebp), %eax imull %esi, %edx movl %edx, -28(%ebp) movl -24(%ebp), %edx imull %edi, %edx addl %edx, -28(%ebp) mull %esi movl %eax, -24(%ebp) movl -28(%ebp), %eax addl %eax, %edx addl $-1, %ecx adcl $-1, %ebx movl %edx, -20(%ebp) movl %ebx, %edx orl %ecx, %edx jne .L16 .L15: movl -24(%ebp), %eax movl -20(%ebp), %edx addl $20, %esp popl %ebx popl %esi popl %edi popl %ebp ret .size uipower_o_n, .-uipower_o_n .p2align 4,,15 .globl uipower_libm .type uipower_libm, @function uipower_libm: pushl %ebp movl %esp, %ebp pushl %ebx subl $52, %esp movl 20(%ebp), %edx movl 16(%ebp), %eax movl 8(%ebp), %ecx movl 12(%ebp), %ebx pushl %edx pushl %eax fildll (%esp) addl $8, %esp testl %edx, %edx js .L25 fstpl 8(%esp) pushl %ebx pushl %ecx fildll (%esp) addl $8, %esp testl %ebx, %ebx js .L26 .L21: fstpl (%esp) call pow flds .LC1 fxch %st(1) fucom %st(1) fnstsw %ax fstp %st(1) sahf jae .L22 fnstcw -18(%ebp) movzwl -18(%ebp), %eax movb $12, %ah movw %ax, -20(%ebp) fldcw -20(%ebp) fistpll -32(%ebp) fldcw -18(%ebp) movl -28(%ebp), %ebx movl -32(%ebp), %ecx addl $52, %esp movl %ebx, %edx popl %ebx movl %ecx, %eax popl %ebp ret .p2align 4,,7 .L22: fnstcw -18(%ebp) fsubs .LC1 movzwl -18(%ebp), %eax movb $12, %ah movw %ax, -20(%ebp) fldcw -20(%ebp) fistpll -32(%ebp) fldcw -18(%ebp) movl -28(%ebp), %ebx movl -32(%ebp), %ecx addl $52, %esp leal -2147483648(%ebx), %edx movl %edx, %ebx movl %ecx, %eax movl %ebx, %edx popl %ebx popl %ebp ret .p2align 4,,7 .L25: fadds .LC0 fstpl 8(%esp) pushl %ebx pushl %ecx fildll (%esp) addl $8, %esp testl %ebx, %ebx jns .L21 .p2align 4,,7 .L26: fadds .LC0 jmp .L21 .size uipower_libm, .-uipower_libm .p2align 4,,15 .globl time_hires .type time_hires, @function time_hires: pushl %ebp movl %esp, %ebp subl $24, %esp leal -8(%ebp), %eax movl $0, 4(%esp) movl %eax, (%esp) call gettimeofday fildl -8(%ebp) fildl -4(%ebp) fdivs .LC3 leave faddp %st, %st(1) ret .size time_hires, .-time_hires .section .rodata.str1.4,"aMS",@progbits,1 .align 4 .LC4: .string "uipower(3,%u)=%llu\t%u\t%.0f\t%.0f\t%0.f\n" .text .p2align 4,,15 .globl main .type main, @function main: leal 4(%esp), %ecx andl $-16, %esp pushl -4(%ecx) pushl %ebp movl %esp, %ebp pushl %edi xorl %edi, %edi pushl %esi xorl %esi, %esi pushl %ebx pushl %ecx subl $104, %esp .L31: movl %esi, -52(%ebp) movl $1, %ebx call time_hires fstpl -40(%ebp) movl %esi, 8(%esp) movl %edi, 12(%esp) movl $3, (%esp) movl $0, 4(%esp) call uipower_o_logn .p2align 4,,7 .L32: movl %esi, 8(%esp) addl $1, %ebx movl %edi, 12(%esp) movl $3, (%esp) movl $0, 4(%esp) call uipower_o_logn cmpl $1000000, %ebx movl %eax, -48(%ebp) movl %edx, -44(%ebp) jne .L32 call time_hires movl $1, %ebx fstpl -72(%ebp) call time_hires fstpl -32(%ebp) movl %esi, 8(%esp) movl %edi, 12(%esp) movl $3, (%esp) movl $0, 4(%esp) call uipower_o_n .p2align 4,,7 .L34: movl %esi, 8(%esp) addl $1, %ebx movl %edi, 12(%esp) movl $3, (%esp) movl $0, 4(%esp) call uipower_o_n cmpl $1000000, %ebx jne .L34 call time_hires fstpl -64(%ebp) call time_hires fstpl -24(%ebp) call time_hires fsubl -24(%ebp) flds .LC3 fmul %st, %st(1) fxch %st(1) fstpl 36(%esp) fldl -64(%ebp) fsubl -32(%ebp) fstl -64(%ebp) fmul %st(1), %st fstpl 28(%esp) fldl -72(%ebp) fsubl -40(%ebp) fmulp %st, %st(1) fstpl 20(%esp) movl -52(%ebp), %eax movl %eax, 16(%esp) movl -44(%ebp), %edx movl -48(%ebp), %eax movl %edx, 12(%esp) movl %eax, 8(%esp) movl -52(%ebp), %edx movl $.LC4, (%esp) movl %edx, 4(%esp) call printf addl $1, %esi movl %esi, %eax adcl $0, %edi xorl $40, %eax orl %edi, %eax jne .L31 addl $104, %esp popl %ecx popl %ebx popl %esi popl %edi popl %ebp leal -4(%ecx), %esp ret .size main, .-main .section .rodata.cst4,"aM",@progbits,4 .align 4 .LC0: .long 1602224128 .align 4 .LC1: .long 1593835520 .align 4 .LC3: .long 1232348160 .ident "GCC: (GNU) 4.2.3 20071123 (prerelease) (Debian 4.2.2-4)" .section .note.GNU-stack,"",@progbits
*1:最適化していない共有ライブラリを別途用意しているなら別だけど
