간단한 함수의 측정 시간을 측정하는데 실행 시간이 0ms로 나옵니다;;
글쓴이: awidesky / 작성시간: 수, 2021/07/21 - 2:34오후
#include <cmath>
#include <iostream>
#include <chrono>
float fsqrt_(float f) {
int i = *(int *)&f;
i = (i >> 1) + 0x1fbb67ae;
float f1 = *(float *)&i;
return 0.5F * (f1 + f / f1);
}
void my_test() {
auto start = std::chrono::high_resolution_clock::now();
float max = 0.0F;
for (int i = 0x00800000 ; i < 0x7f800000 ; i++) {
float f = *(float*) &i;
float re = fsqrt_(f);
if(max < re) max = re;
}
auto end1 = std::chrono::high_resolution_clock::now();
auto diff = end1 - start;
std::cout << "mysqrt : " << std::chrono::duration <double, std::milli> (diff).count() << " ms" << std::endl;
}
void lib_test() {
auto start = std::chrono::high_resolution_clock::now();
float max = 0.0F;
for (int i = 0x00800000 ; i < 0x7f800000 ; i++) {
float f = *(float*) &i;
float re = sqrtf(f);
if(max < re) max = re;
}
auto end1 = std::chrono::high_resolution_clock::now();
auto diff = end1 - start;
std::cout << "stdlib : " << std::chrono::duration <double, std::milli> (diff).count() << " ms" << std::endl;
}
int main() {
std::cout << "warmup" << std::endl;
for(int i = 0 ; i < 3 ; i++) {
my_test();
lib_test();
}
std::cout << "\ntest\n" << std::endl;
for(int i = 0 ; i < 5 ; i++) {
my_test();
lib_test();
}
}게임 퀘이크 3의 fast invsqrt 함수에서 영감을 받아 만든 sqrt함수의 실행시간을 측정해보려 합니다. 컴파일 및 실행 명령은 다음과 같습니다.
g++ --version g++ speed_test.cpp -O3 -o speed_test.exe speed_test.exe
측정 방법은 제가 만든 fsqrt_()와 cmath의 sqrtf 모두 동일한데, 이상하게 출력이 이렇게 나옵니다.
D:\development\gitRepos\MyPapers\fsqrt\code>g++ --version g++ (x86_64-win32-seh-rev0, Built by MinGW-W64 project) 8.1.0 Copyright (C) 2018 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. D:\development\gitRepos\MyPapers\fsqrt\code>g++ speed_test.cpp -O3 -o speed_test.exe D:\development\gitRepos\MyPapers\fsqrt\code>speed_test.exe warmup mysqrt : 0 ms stdlib : 1241.64 ms mysqrt : 0 ms stdlib : 1223.3 ms mysqrt : 0 ms stdlib : 1235.76 ms test mysqrt : 0 ms stdlib : 1229.85 ms mysqrt : 0 ms stdlib : 1240.04 ms mysqrt : 0 ms stdlib : 1235.71 ms mysqrt : 0 ms stdlib : 1266.09 ms mysqrt : 0 ms stdlib : 1247.12 ms D:\development\gitRepos\MyPapers\fsqrt\code>pause 계속하려면 아무 키나 누르십시오 . . .
제가 알지 못하는 사이에 최적화가 일어나기라도 한 건지;;; 반복 횟수를 늘려봐도 동일하게 나옵니다..
Forums:
혹시 최적화로 반복이나 함수 호출문이 없어졌나 해서 objdump로 덤프 해봤는데 그렇지는 않은 것 같습니다..
my_asm_output.o: file format pe-x86-64 Disassembly of section .text: 0000000000000000 <_Z6fsqrt_f>: #include <cmath> #include <iostream> #include <chrono> float fsqrt_(float f) { 0: 55 push %rbp 1: 48 89 e5 mov %rsp,%rbp 4: 48 83 ec 10 sub $0x10,%rsp 8: f3 0f 11 45 10 movss %xmm0,0x10(%rbp) int i = *(int *)&f; d: 48 8d 45 10 lea 0x10(%rbp),%rax 11: 8b 00 mov (%rax),%eax 13: 89 45 f8 mov %eax,-0x8(%rbp) i = (i >> 1) + 0x1fbb67ae; 16: 8b 45 f8 mov -0x8(%rbp),%eax 19: d1 f8 sar %eax 1b: 05 ae 67 bb 1f add $0x1fbb67ae,%eax 20: 89 45 f8 mov %eax,-0x8(%rbp) float f1 = *(float *)&i; 23: 48 8d 45 f8 lea -0x8(%rbp),%rax 27: f3 0f 10 00 movss (%rax),%xmm0 2b: f3 0f 11 45 fc movss %xmm0,-0x4(%rbp) return 0.5F * (f1 + f / f1); 30: f3 0f 10 45 10 movss 0x10(%rbp),%xmm0 35: f3 0f 5e 45 fc divss -0x4(%rbp),%xmm0 3a: 0f 28 c8 movaps %xmm0,%xmm1 3d: f3 0f 58 4d fc addss -0x4(%rbp),%xmm1 42: f3 0f 10 05 28 00 00 movss 0x28(%rip),%xmm0 # 72 <_Z7my_testv+0x1e> 49: 00 4a: f3 0f 59 c1 mulss %xmm1,%xmm0 } 4e: 48 83 c4 10 add $0x10,%rsp 52: 5d pop %rbp 53: c3 retq 0000000000000054 <_Z7my_testv>: void my_test() { 54: 55 push %rbp 55: 53 push %rbx 56: 48 83 ec 68 sub $0x68,%rsp 5a: 48 8d ac 24 80 00 00 lea 0x80(%rsp),%rbp 61: 00 auto start = std::chrono::high_resolution_clock::now(); 62: e8 00 00 00 00 callq 67 <_Z7my_testv+0x13> 67: 48 89 45 c0 mov %rax,-0x40(%rbp) float max = 0.0F; 6b: 66 0f ef c0 pxor %xmm0,%xmm0 6f: f3 0f 11 45 dc movss %xmm0,-0x24(%rbp) for (int i = 0x00800000 ; i < 0x7f800000 ; i++) { 74: c7 45 ac 00 00 80 00 movl $0x800000,-0x54(%rbp) 7b: 8b 45 ac mov -0x54(%rbp),%eax 7e: 3d ff ff 7f 7f cmp $0x7f7fffff,%eax 83: 7f 40 jg c5 <_Z7my_testv+0x71> float f = *(float*) &i; 85: 48 8d 45 ac lea -0x54(%rbp),%rax 89: f3 0f 10 00 movss (%rax),%xmm0 8d: f3 0f 11 45 d8 movss %xmm0,-0x28(%rbp) float re = fsqrt_(f); 92: 8b 45 d8 mov -0x28(%rbp),%eax 95: 66 0f 6e c0 movd %eax,%xmm0 99: e8 62 ff ff ff callq 0 <_Z6fsqrt_f> 9e: 66 0f 7e c0 movd %xmm0,%eax a2: 89 45 d4 mov %eax,-0x2c(%rbp) if(max < re) max = re; a5: f3 0f 10 45 d4 movss -0x2c(%rbp),%xmm0 aa: 0f 2f 45 dc comiss -0x24(%rbp),%xmm0 ae: 76 0a jbe ba <_Z7my_testv+0x66> b0: f3 0f 10 45 d4 movss -0x2c(%rbp),%xmm0 b5: f3 0f 11 45 dc movss %xmm0,-0x24(%rbp) for (int i = 0x00800000 ; i < 0x7f800000 ; i++) { ba: 8b 45 ac mov -0x54(%rbp),%eax bd: 83 c0 01 add $0x1,%eax c0: 89 45 ac mov %eax,-0x54(%rbp) c3: eb b6 jmp 7b <_Z7my_testv+0x27> } auto end1 = std::chrono::high_resolution_clock::now(); c5: e8 00 00 00 00 callq ca <_Z7my_testv+0x76> ca: 48 89 45 b8 mov %rax,-0x48(%rbp) auto diff = end1 - start; ce: 48 8d 55 c0 lea -0x40(%rbp),%rdx d2: 48 8d 45 b8 lea -0x48(%rbp),%rax d6: 48 89 c1 mov %rax,%rcx d9: e8 00 00 00 00 callq de <_Z7my_testv+0x8a> de: 48 89 45 b0 mov %rax,-0x50(%rbp) std::cout << "mysqrt : " << std::chrono::duration <double, std::milli> (diff).count() << " ms" << std::endl; e2: 48 8d 15 01 00 00 00 lea 0x1(%rip),%rdx # ea <_Z7my_testv+0x96> e9: 48 8b 0d 00 00 00 00 mov 0x0(%rip),%rcx # f0 <_Z7my_testv+0x9c> f0: e8 00 00 00 00 callq f5 <_Z7my_testv+0xa1> f5: 48 89 c3 mov %rax,%rbx f8: 48 8d 55 b0 lea -0x50(%rbp),%rdx fc: 48 8d 45 c8 lea -0x38(%rbp),%rax 100: 48 89 c1 mov %rax,%rcx 103: e8 00 00 00 00 callq 108 <_Z7my_testv+0xb4> 108: 48 8d 45 c8 lea -0x38(%rbp),%rax 10c: 48 89 c1 mov %rax,%rcx 10f: e8 00 00 00 00 callq 114 <_Z7my_testv+0xc0> 114: 66 48 0f 7e c0 movq %xmm0,%rax 119: 66 48 0f 6e c8 movq %rax,%xmm1 11e: 48 89 d9 mov %rbx,%rcx 121: e8 00 00 00 00 callq 126 <_Z7my_testv+0xd2> 126: 48 8d 15 0b 00 00 00 lea 0xb(%rip),%rdx # 138 <_Z7my_testv+0xe4> 12d: 48 89 c1 mov %rax,%rcx 130: e8 00 00 00 00 callq 135 <_Z7my_testv+0xe1> 135: 48 8b 15 00 00 00 00 mov 0x0(%rip),%rdx # 13c <_Z7my_testv+0xe8> 13c: 48 89 c1 mov %rax,%rcx 13f: e8 00 00 00 00 callq 144 <_Z7my_testv+0xf0> } 144: 90 nop 145: 48 83 c4 68 add $0x68,%rsp 149: 5b pop %rbx 14a: 5d pop %rbp 14b: c3 retq 000000000000014c <_Z8lib_testv>: void lib_test() { 14c: 55 push %rbp 14d: 53 push %rbx 14e: 48 83 ec 68 sub $0x68,%rsp 152: 48 8d ac 24 80 00 00 lea 0x80(%rsp),%rbp 159: 00 auto start = std::chrono::high_resolution_clock::now(); 15a: e8 00 00 00 00 callq 15f <_Z8lib_testv+0x13> 15f: 48 89 45 c0 mov %rax,-0x40(%rbp) float max = 0.0F; 163: 66 0f ef c0 pxor %xmm0,%xmm0 167: f3 0f 11 45 dc movss %xmm0,-0x24(%rbp) for (int i = 0x00800000 ; i < 0x7f800000 ; i++) { 16c: c7 45 ac 00 00 80 00 movl $0x800000,-0x54(%rbp) 173: 8b 45 ac mov -0x54(%rbp),%eax 176: 3d ff ff 7f 7f cmp $0x7f7fffff,%eax 17b: 7f 40 jg 1bd <_Z8lib_testv+0x71> float f = *(float*) &i; 17d: 48 8d 45 ac lea -0x54(%rbp),%rax 181: f3 0f 10 00 movss (%rax),%xmm0 185: f3 0f 11 45 d8 movss %xmm0,-0x28(%rbp) float re = sqrtf(f); 18a: 8b 45 d8 mov -0x28(%rbp),%eax 18d: 66 0f 6e c0 movd %eax,%xmm0 191: e8 00 00 00 00 callq 196 <_Z8lib_testv+0x4a> 196: 66 0f 7e c0 movd %xmm0,%eax 19a: 89 45 d4 mov %eax,-0x2c(%rbp) if(max < re) max = re; 19d: f3 0f 10 45 d4 movss -0x2c(%rbp),%xmm0 1a2: 0f 2f 45 dc comiss -0x24(%rbp),%xmm0 1a6: 76 0a jbe 1b2 <_Z8lib_testv+0x66> 1a8: f3 0f 10 45 d4 movss -0x2c(%rbp),%xmm0 1ad: f3 0f 11 45 dc movss %xmm0,-0x24(%rbp) for (int i = 0x00800000 ; i < 0x7f800000 ; i++) { 1b2: 8b 45 ac mov -0x54(%rbp),%eax 1b5: 83 c0 01 add $0x1,%eax 1b8: 89 45 ac mov %eax,-0x54(%rbp) 1bb: eb b6 jmp 173 <_Z8lib_testv+0x27> } auto end1 = std::chrono::high_resolution_clock::now(); 1bd: e8 00 00 00 00 callq 1c2 <_Z8lib_testv+0x76> 1c2: 48 89 45 b8 mov %rax,-0x48(%rbp) auto diff = end1 - start; 1c6: 48 8d 55 c0 lea -0x40(%rbp),%rdx 1ca: 48 8d 45 b8 lea -0x48(%rbp),%rax 1ce: 48 89 c1 mov %rax,%rcx 1d1: e8 00 00 00 00 callq 1d6 <_Z8lib_testv+0x8a> 1d6: 48 89 45 b0 mov %rax,-0x50(%rbp) std::cout << "stdlib : " << std::chrono::duration <double, std::milli> (diff).count() << " ms" << std::endl; 1da: 48 8d 15 0f 00 00 00 lea 0xf(%rip),%rdx # 1f0 <_Z8lib_testv+0xa4> 1e1: 48 8b 0d 00 00 00 00 mov 0x0(%rip),%rcx # 1e8 <_Z8lib_testv+0x9c> 1e8: e8 00 00 00 00 callq 1ed <_Z8lib_testv+0xa1> 1ed: 48 89 c3 mov %rax,%rbx 1f0: 48 8d 55 b0 lea -0x50(%rbp),%rdx 1f4: 48 8d 45 c8 lea -0x38(%rbp),%rax 1f8: 48 89 c1 mov %rax,%rcx 1fb: e8 00 00 00 00 callq 200 <_Z8lib_testv+0xb4> 200: 48 8d 45 c8 lea -0x38(%rbp),%rax 204: 48 89 c1 mov %rax,%rcx 207: e8 00 00 00 00 callq 20c <_Z8lib_testv+0xc0> 20c: 66 48 0f 7e c0 movq %xmm0,%rax 211: 66 48 0f 6e c8 movq %rax,%xmm1 216: 48 89 d9 mov %rbx,%rcx 219: e8 00 00 00 00 callq 21e <_Z8lib_testv+0xd2> 21e: 48 8d 15 0b 00 00 00 lea 0xb(%rip),%rdx # 230 <_Z8lib_testv+0xe4> 225: 48 89 c1 mov %rax,%rcx 228: e8 00 00 00 00 callq 22d <_Z8lib_testv+0xe1> 22d: 48 8b 15 00 00 00 00 mov 0x0(%rip),%rdx # 234 <_Z8lib_testv+0xe8> 234: 48 89 c1 mov %rax,%rcx 237: e8 00 00 00 00 callq 23c <_Z8lib_testv+0xf0> } 23c: 90 nop 23d: 48 83 c4 68 add $0x68,%rsp 241: 5b pop %rbx 242: 5d pop %rbp 243: c3 retq 0000000000000244 <main>: int main() { 244: 55 push %rbp 245: 48 89 e5 mov %rsp,%rbp 248: 48 83 ec 30 sub $0x30,%rsp 24c: e8 00 00 00 00 callq 251 <main+0xd> std::cout << "warmup" << std::endl; 251: 48 8d 15 19 00 00 00 lea 0x19(%rip),%rdx # 271 <main+0x2d> 258: 48 8b 0d 00 00 00 00 mov 0x0(%rip),%rcx # 25f <main+0x1b> 25f: e8 00 00 00 00 callq 264 <main+0x20> 264: 48 8b 15 00 00 00 00 mov 0x0(%rip),%rdx # 26b <main+0x27> 26b: 48 89 c1 mov %rax,%rcx 26e: e8 00 00 00 00 callq 273 <main+0x2f> for(int i = 0 ; i < 3 ; i++) { 273: c7 45 fc 00 00 00 00 movl $0x0,-0x4(%rbp) 27a: 83 7d fc 02 cmpl $0x2,-0x4(%rbp) 27e: 7f 10 jg 290 <main+0x4c> my_test(); 280: e8 cf fd ff ff callq 54 <_Z7my_testv> lib_test(); 285: e8 c2 fe ff ff callq 14c <_Z8lib_testv> for(int i = 0 ; i < 3 ; i++) { 28a: 83 45 fc 01 addl $0x1,-0x4(%rbp) 28e: eb ea jmp 27a <main+0x36> } std::cout << "\n\ntest\n" << std::endl; 290: 48 8d 15 20 00 00 00 lea 0x20(%rip),%rdx # 2b7 <main+0x73> 297: 48 8b 0d 00 00 00 00 mov 0x0(%rip),%rcx # 29e <main+0x5a> 29e: e8 00 00 00 00 callq 2a3 <main+0x5f> 2a3: 48 8b 15 00 00 00 00 mov 0x0(%rip),%rdx # 2aa <main+0x66> 2aa: 48 89 c1 mov %rax,%rcx 2ad: e8 00 00 00 00 callq 2b2 <main+0x6e> for(int i = 0 ; i < 5 ; i++) { 2b2: c7 45 f8 00 00 00 00 movl $0x0,-0x8(%rbp) 2b9: 83 7d f8 04 cmpl $0x4,-0x8(%rbp) 2bd: 7f 10 jg 2cf <main+0x8b> my_test(); 2bf: e8 90 fd ff ff callq 54 <_Z7my_testv> lib_test(); 2c4: e8 83 fe ff ff callq 14c <_Z8lib_testv> for(int i = 0 ; i < 5 ; i++) { 2c9: 83 45 f8 01 addl $0x1,-0x8(%rbp) 2cd: eb ea jmp 2b9 <main+0x75> } 2cf: b8 00 00 00 00 mov $0x0,%eax 2d4: 48 83 c4 30 add $0x30,%rsp 2d8: 5d pop %rbp 2d9: c3 retq이진 코드는 잘 모르겠으나, 최적화에 의해서 루프가
이진 코드는 잘 모르겠으나, 최적화에 의해서 루프가 무시되는 것 같습니다.
cout 라인에 max 를 출력하도록 하면 시간이 정상적으로 나오네요.
감사합니다!
그런데 혹시 제가 만든 함수만 반복이 무시되는 이유를 알 수 있을까요?
함수 iteration 순서를 바꾸어도 똑같은 문제가 생기네요;;
라이브러리의 함수는 이미 컴파일되어 있기 때문에 코드가 있는 제 함수만 루프 최적화의 대상이 되는 것인가요?
전공자가 아니라 모르겠으나, 눈에 보이는 차이는,
전공자가 아니라 모르겠으나, 눈에 보이는 차이는,
직접 만든 함수의 경우 모든 코드를 컴파일러가 볼 수 있으니 side effect가 없다고 판단해서
루프를 무시하는 것이 아닐까요?
라이브러리의 함수는 함수 내용을 컴파일러가 모르니, side effecect가 있을 수 있으니,
루프를 돌아야하고요.
최적화 옵션을 왜 넣으셨나요
빌드할 때 -O3 옵션을 빼면 원하시는대로 출력이 되네요
컴파일러 최적화를 끄면 0 아닌 값이 나올 수는
컴파일러 최적화를 끄면 0 아닌 값이 나올 수는 있겠으나...
그렇게 해서 측정된 값이 내가 원래 측정하려던 값이 맞는지는 또 다른 문제이지요.
-O3 최적화는 코드 내용을 바꿔버리는 최적화인데요?
O3를 통해 실행한 코드가 내가 적은 코드가 아닌데
이런 코드 실행 시간을 측정하는 목적에서는 빼는게 맞죠
모든 최적화가 코드 내용을 바꾸는 최적화이죠.
모든 최적화가 코드 내용을 바꾸는 최적화이죠.
요점은 내가 의도한 프로그램의 동작을 유지하는 선에서 코드를 바꿔야 한다는 것인데...
-ffast-math처럼 명시적으로 프로그램의 동작을 바꿀 수 있는 옵션이 아니더라도, C/C++ 언어 표준은 교묘한 부분들이 좀 있어서 설령 적법한 최적화라 해도 내가 의도했던 동작이 최적화 과정에서 보존이 될지 확신하기 까다로운 경우들이 많지요.
-ffast-math는 -O3에서 켜지는 최적화는 아니긴 합니다만, 뭐 아무튼.
======
뭐 그런 의미에서 -O3의 사용은 좀 controversial 할 수 있어요. 비판하는 사람들은 -O2 대비 더 좋다는 보장도 없는데다가 위험천만하다고 그러더군요.
근데 그렇다고 -O3 빼고 돌리면 디폴트로 -O0이 들어갈 텐데, 그건 좀 아니지 않을까요.
아마 -O3 최적화가 해당 코드 자체가 필요없다고 빼
아마 -O3 최적화가 해당 코드 자체가 필요없다고 빼 버리는 것 같은데 my_test() 내에서 끝에 max, re 값 등을 출력해 보면 바뀌어 질 것 같네요. 변수 자체에 volatile을 쓰면 그 쪽 자체에 최적화가 빠지게 되니까 그건 참고하시고요.
댓글 달기