Microsoft MVP성태의 닷넷 이야기
글쓴 사람
정성태 (techsharer at outlook.com)
홈페이지
첨부 파일

닷넷 (및 VM 계열 언어) 코드의 성능 측정 시 주의할 점

아래와 같은 글이 있군요. ^^

c# 에서 문자열 계산속도
; http://www.gamecodi.com/board/zboard-id-GAMECODI_Talkdev-no-5247-z-2.htm

그런데, 위의 코드는 잘못된 방식의 성능 측정을 하고 있습니다. 왜냐하면 초기 JIT 컴파일을 생각하지 않고 작성한 코드인데 정상적으로 바꿔보면 다음과 같이 테스트할 수 있습니다.

using System;
using System.Diagnostics;

class Program
{
    static void Main(string[] args)
    {
        Action<int, string, Action<int, string>, string> action = (loopCount, title, work, arg) =>
        {
            Stopwatch st = new Stopwatch();
            st.Start();

            work(loopCount, arg);

            st.Stop();

            Console.WriteLine(title + " : " + st.ElapsedMilliseconds);
        };

        action(1, "ConcatText for JIT", ConcatText, "");
        action(1, "InterpolateText for JIT", InterpolateText, "");
        action(1, "FormatText for JIT", FormatText, "");

        Console.WriteLine();

        action(10000000, "ConcatText", ConcatText, "");
        action(10000000, "InterpolateText", InterpolateText, "");
        action(10000000, "FormatText", FormatText, "");
    }

    private static void ConcatText(int loopCount, string text)
    {
        for (int i = 0; i < loopCount; i ++)
        {
            TestLog(text + "a");
        }
    }

    private static void InterpolateText(int loopCount, string text)
    {
        for (int i = 0; i < loopCount; i++)
        {
            TestLog($"{text}a");
        }
    }

    private static void FormatText(int loopCount, string text)
    {
        for (int i = 0; i < loopCount; i++)
        {
            TestLog("{0}a", text);
        }
    }

    static void TestLog(string format, params object [] args)
    {
    }
}

보는 바와 같이 JIT 컴파일로 인한 부하를 제거하고 다시 본격적인 성능 측정을 하도록 바뀌었습니다. 그래서 "c# 에서 문자열 계산속도" 글에서의 출력과,

String Concat took: 150 ms
String Interpolation took: 141 ms
String Format took: 191 ms

제가 테스트한 출력 결과를 보면,

[x86 - Debug 빌드]

ConcatText : 116
InterpolateText : 116
FormatText : 120

결과가 다릅니다. 그런데 이것을 릴리스 빌드로 하면 다시 차이가 발생합니다.

[x86 - Release 빌드]

ConcatText : 100
InterpolateText : 33
FormatText : 70

재미있는 것은 JIT 컴파일 방식이 개선된 x64에서는 다시 이런 결과가 나옵니다.

[x64 - Debug 빌드]

ConcatText : 175
InterpolateText : 114
FormatText : 111

[x64 - Release 빌드]

ConcatText : 80
InterpolateText : 31
FormatText : 80

그런데, 아직 끝이 아닙니다. ^^




(이하, 테스트는 x64 - Release 빌드의 결과만 다룹니다.)

잠시 살펴보면, 마지막 Format 코드에 대한 테스트가 잘못되었습니다. 원래 의도는 string.Format을 호출하는 것이었을 텐데 단순히 TestLog에 인자를 넘기는 동작만 하기 때문에 사실 문자열 연산과는 크게 관련이 없습니다. 따라서 원래 의도를 반영하려면 다음과 같이 바꿔야 하고,

private static void FormatText(int loopCount, string text)
{
    for (int i = 0; i < loopCount; i++)
    {
        TestLog(string.Format("{0}a", text));
    }
}

이렇게 되면 출력 결과가 완전히 달라집니다.

[x64 - Release 빌드]

ConcatText : 77
InterpolateText : 31
FormatText : 716

여기서 더욱 재미있는 것은, IL 코드입니다. 다르게 작성한 ConcatText, InterpolateText 메서드는,

private static void ConcatText(int loopCount, string text)
{
    for (int i = 0; i < loopCount; i++)
    {
        TestLog(text + "a");
    }
}

private static void InterpolateText(int loopCount, string text)
{
    for (int i = 0; i < loopCount; i++)
    {
        TestLog($"{text}a");
    }
}

다음과 같이 동일한 IL 코드로 번역됩니다.

for (int i = 0; i < loopCount; i++)
{
    TestLog(text + "a", Array.Empty<object>());
}

그러니까, C# 컴파일러는 $"{text}"a 코드를 원래는 string.Format으로 바꿔야 하지만 어차피 2개의 문자열을 하나로 합치는 것이므로 단순히 concat 연산자로 처리하는 것이 더 빠르다고 판단해 최적화를 해버립니다.

아니... 근데, 그럼 IL 코드가 같은 그 2개의 메서드가 성능이 왜 다른 것일까요? 저도 모르겠습니다. ^^; 단지 현상을 보려면 JIT 컴파일된 기계어를 보면 됩니다. 다음은 ConcatText 메서드가 JIT 컴파일된 결과입니다.

// ConcatText

    33:         for (int i = 0; i < loopCount; i++)
00007FF9DD360D32 53                   push        rbx  
00007FF9DD360D33 48 83 EC 20          sub         rsp,20h  
00007FF9DD360D37 8B F1                mov         esi,ecx  
00007FF9DD360D39 48 8B FA             mov         rdi,rdx  
00007FF9DD360D3C 33 DB                xor         ebx,ebx  
00007FF9DD360D3E 85 F6                test        esi,esi  
00007FF9DD360D40 7E 2A                jle         00007FF9DD360D6C  
    34:         {
    35:             TestLog(text + "a");
00007FF9DD360D42 48 BA 90 36 00 90 76 01 00 00 mov         rdx,17690003690h  
00007FF9DD360D4C 48 8B 12             mov         rdx,qword ptr [rdx]  
00007FF9DD360D4F 48 8B CF             mov         rcx,rdi  
00007FF9DD360D52 E8 59 87 F9 5C       call        00007FFA3A2F94B0  
00007FF9DD360D57 B9 01 00 00 00       mov         ecx,1  
00007FF9DD360D5C BA 53 00 00 00       mov         edx,53h  
00007FF9DD360D61 E8 6A 22 6E 5F       call        00007FFA3CA42FD0  
    33:         for (int i = 0; i < loopCount; i++)
00007FF9DD360D66 FF C3                inc         ebx  
00007FF9DD360D68 3B DE                cmp         ebx,esi  
00007FF9DD360D6A 7C D6                jl          00007FF9DD360D42  
00007FF9DD360D6C 48 83 C4 20          add         rsp,20h  
00007FF9DD360D70 5B                   pop         rbx  
00007FF9DD360D71 5E                   pop         rsi  
00007FF9DD360D72 5F                   pop         rdi  
00007FF9DD360D73 C3                   ret  
}

반면 InterpolateText는 (ConcatText와 동일한 IL 코드였음에도 불구하고) 다음과 같이 call 하나가 빠져 있습니다.

// InterpolateText

    41:         for (int i = 0; i < loopCount; i++)
00007FF9DD380D92 53                   push        rbx  
00007FF9DD380D93 48 83 EC 20          sub         rsp,20h  
00007FF9DD380D97 8B F1                mov         esi,ecx  
00007FF9DD380D99 48 8B FA             mov         rdi,rdx  
00007FF9DD380D9C 33 DB                xor         ebx,ebx  
00007FF9DD380D9E 85 F6                test        esi,esi  
00007FF9DD380DA0 7E 1B                jle         00007FF9DD380DBD  
    42:         {
    43:             TestLog($"{text}a");
00007FF9DD380DA2 48 BA 90 36 BC 64 6E 01 00 00 mov         rdx,16E64BC3690h  
00007FF9DD380DAC 48 8B 12             mov         rdx,qword ptr [rdx]  
00007FF9DD380DAF 48 8B CF             mov         rcx,rdi  
00007FF9DD380DB2 E8 F9 86 F7 5C       call        00007FFA3A2F94B0  
    41:         for (int i = 0; i < loopCount; i++)
00007FF9DD380DB7 FF C3                inc         ebx  
00007FF9DD380DB9 3B DE                cmp         ebx,esi  
00007FF9DD380DBB 7C E5                jl          00007FF9DD380DA2  
00007FF9DD380DBD 48 83 C4 20          add         rsp,20h  
00007FF9DD380DC1 5B                   pop         rbx  
00007FF9DD380DC2 5E                   pop         rsi  
00007FF9DD380DC3 5F                   pop         rdi  
00007FF9DD380DC4 C3                   ret  
}

이유는 알 수 없지만, 어쨌든 x64 JIT 컴파일러는 한 쪽 메서드에만 다음의 call 하나를 추가한 탓에 성능 차이가 발생합니다.

00007FF9DD360D57 B9 01 00 00 00       mov         ecx,1  
00007FF9DD360D5C BA 53 00 00 00       mov         edx,53h  
00007FF9DD360D61 E8 6A 22 6E 5F       call        00007FFA3CA42FD0  

첫 번째 인자에 1을 넣고 두 번째 인자에 83 (0x53)을 넣어 함수를 호출하는데 도대체 알 수 없는 코드입니다. ^^;

정리해 보면, (위의 환경에서) ConcatText나 InterpolateText는 완전히 같은 처리를 합니다. 따라서 string.Format으로 명시적인 호출을 발생하는 FormatText만 유독 크게 성능이 떨어지는 것처럼 보입니다.

반면, Interpolate의 문자열이 좀 더 복잡해진다면... 그래서2 C# 컴파일러가 string.Format으로 번역하게 된다면 이번에는 InterpolateText와 FormatText의 성능이 같을 것입니다.

(첨부 파일은 이 글의 예제 코드를 포함합니다.)




그러니까... C#과 같은 VM 환경의 언어에서는 성능 측정이 매우 까다롭습니다. 그래서, 어느 게 좋고 어느 게 나쁘다는 것을 판정하려면 꽤나 주의를 기울여야 하고 따질 것이 많습니다. 경험상, 닷넷 코드의 성능을 측정 시에는 적어도 다음의 요인들을 잘 살펴야 합니다.

  • 플랫폼 및 빌드 모드 표시(경우에 따라, .NET Framework 버전 명시)
  • 초기 JIT 컴파일 시간 영향 제거
  • C# 컴파일 단계에서의 최적화로 인한 차이
  • JIT 컴파일 단계에서의 최적화로 인한 차이




[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]

[연관 글]





[최초 등록일: ]
[최종 수정일: 8/14/2019 ]

Creative Commons License
이 저작물은 크리에이티브 커먼즈 코리아 저작자표시-비영리-변경금지 2.0 대한민국 라이센스에 따라 이용하실 수 있습니다.
by SeongTae Jeong, mailto:techsharer@outlook.com

비밀번호

댓글 쓴 사람
 



2019-08-14 01시55분
[폴리모프] (^-^)b
[손님]
2019-08-20 01시05분
저도 겜코디 쓰레드 읽으면서 뭔가 이상한데라고 느꼈는데, 이렇게 테스트하셔서 글을 올려주셨네요! 감사합니다.

성능 측정하는 글들이 여러군데 흩어져 있는데, 이번에 나온 책에서는 저 부분이 어느정도 모아져 있어 참고하기 괜찮았었네요!

- Pro .NET Benchmarking : https://www.apress.com/gp/book/9781484249406
Eunpyoung Kim

1  2  3  4  5  6  7  8  [9]  10  11  12  13  14  15  ...
NoWriterDateCnt.TitleFile(s)
12148정성태2/23/2020716디버깅 기술: 163. x64 환경에서 구현하는 다양한 Trampoline 기법
12147정성태2/27/2020569디버깅 기술: 162. x86/x64의 기계어 코드 최대 길이
12146정성태2/18/2020637.NET Framework: 893. eBEST C# XingAPI 래퍼 - 로그인 처리파일 다운로드1
12145정성태2/18/2020583.NET Framework: 892. eBEST C# XingAPI 래퍼 - Sqlite 지원 추가파일 다운로드1
12144정성태2/23/2020590.NET Framework: 891. 실행 시에 메서드 가로채기 - CLR Injection: Runtime Method Replacer 개선 - 두 번째 이야기파일 다운로드1
12143정성태2/13/2020442.NET Framework: 890. 상황별 GetFunctionPointer 반환값 정리 - x64파일 다운로드1
12142정성태2/27/2020601.NET Framework: 889. C# 코드로 접근하는 MethodDesc, MethodTable파일 다운로드1
12141정성태2/10/2020688.NET Framework: 888. C# - ASP.NET Core 웹 응용 프로그램의 출력 가로채기 [1]파일 다운로드1
12140정성태2/10/2020543.NET Framework: 887. C# - ASP.NET 웹 응용 프로그램의 출력 가로채기파일 다운로드1
12139정성태2/9/2020784.NET Framework: 886. C# - Console 응용 프로그램에서 UI 스레드 구현 방법
12138정성태2/9/2020946.NET Framework: 885. C# - 닷넷 응용 프로그램에서 Sqlite 사용 [3]파일 다운로드1
12137정성태2/9/2020500오류 유형: 592. [AhnLab] 경고 - 디버거 실행을 탐지했습니다.
12136정성태9/24/2020444Windows: 168. Windows + S(또는 Q)로 뜨는 작업 표시줄의 검색 바가 동작하지 않는 경우
12135정성태7/9/2020572개발 환경 구성: 468. Nuget 패키지의 로컬 보관 폴더를 옮기는 방법 [1]
12134정성태2/5/20201409.NET Framework: 884. eBEST XingAPI의 C# 래퍼 버전 - XingAPINet Nuget 패키지 [2]파일 다운로드1
12133정성태2/7/2020632디버깅 기술: 161. Windbg 환경에서 확인해 본 .NET 메서드 JIT 컴파일 전과 후 - 두 번째 이야기
12132정성태2/20/2020888.NET Framework: 883. C#으로 구현하는 Win32 API 후킹(예: Sleep 호출 가로채기)파일 다운로드1
12131정성태1/27/2020997개발 환경 구성: 467. LocaleEmulator를 이용해 유니코드를 지원하지 않는(한글이 깨지는) 프로그램을 실행하는 방법
12130정성태1/26/2020547VS.NET IDE: 142. Visual Studio에서 windbg의 "Open Executable..."처럼 EXE를 직접 열어 디버깅을 시작하는 방법
12129정성태1/26/20201872.NET Framework: 882. C# - 키움 Open API+ 사용 시 Registry 등록 없이 KHOpenAPI.ocx 사용하는 방법 [1]
12128정성태1/26/2020643오류 유형: 591. The code execution cannot proceed because mfc100.dll was not found. Reinstalling the program may fix this problem.
12127정성태1/28/2020667.NET Framework: 881. C# DLL에서 제공하는 Win32 export 함수의 내부 동작 방식(VT Fix up Table)파일 다운로드1
12126정성태1/25/2020612.NET Framework: 880. C# - PE 파일로부터 IMAGE_COR20_HEADER 및 VTableFixups 테이블 분석파일 다운로드1
12125정성태1/24/2020482VS.NET IDE: 141. IDE0019 - Use pattern matching
12124정성태1/24/20201050VS.NET IDE: 140. IDE1006 - Naming rule violation: These words must begin with upper case characters: ...
12123정성태1/23/2020833웹: 39. Google Analytics - gtag 함수를 이용해 페이지 URL 수정 및 별도의 이벤트 생성 방법
1  2  3  4  5  6  7  8  [9]  10  11  12  13  14  15  ...