닷넷 환경이 왜 C/C++보다 느릴까요?
어디... windbg 실습 좀 할 겸 한번 살펴볼까요? ^^ 관리 환경이 네이티브보다 느린 전형적인 사례라면 바로 배열 접근이 있는데요. 예제는 다음과 같이 간단하게 구성했습니다.
// x86 exe 디버그 빌드
class Program
{
static void Main(string[] args)
{
int [] arr1 = new int[2] { 0x1234, 0x5678 };
int[] arr2 = arr1;
Console.ReadLine();
}
}
windbg를 실행하고, 예제 EXE 프로그램을 열어 실행합니다. 그럼 곧바로 프로그램 실행 초기에 windbg가 연결되면서 실행이 멈춥니다.
아래의 글에 설명했던 방법에 따라 Main 메서드에 BP를 걸텐데요.
(Managed) Main Method에 Break Point 걸기
; https://www.sysnet.pe.kr/2/0/469
우선 SOS를 로드하고,
0:000> sxe ld clr
0:000> g
ModLoad: 72240000 728d2000 C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
eax=00000000 ebx=00800000 ecx=00000000 edx=00000000 esi=00000000 edi=7edfe000
eip=77d70fe8 esp=010ff06c ebp=010ff0c4 iopl=0 nv up ei pl nz na pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000206
ntdll!NtMapViewOfSection+0xc:
77d70fe8 c22800 ret 28h
0:000> .loadby sos clr
여기서부터는 .NET 4.5로 테스트한 거라서 약간 상황이 달라졌습니다. clr.dll의 RunMain 메서드에 BP가 걸리게 하고,
0:000> bp clr!RunMain
0:000> g
(46ec.47c8): Unknown exception - code 04242420 (first chance)
Breakpoint 0 hit
eax=010ff028 ebx=00000000 ecx=01273794 edx=00000000 esi=00000000 edi=01273794
eip=72307dde esp=010ff008 ebp=010ff278 iopl=0 nv up ei pl zr na pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000246
clr!RunMain:
72307dde 6800010000 push 100h
Main 메서드에 BP를 거는 sos 확장 기능을 이용합니다.
0:000> !bpmd ConsoleApplication1 Program.Main
Found 1 methods in module 01272e94...
MethodDesc = 01273794
Adding pending breakpoints.
g 키를 다시 2번 정도 누르면 Main 메서드의 JIT가 완료된 시점에 프로그램 실행이 다시 멈춥니다.
0:000> g
(46ec.47c8): CLR notification exception - code e0444143 (first chance)
JITTED ConsoleApplication1!Program.Main(System.String[])
Setting breakpoint: bp 013F007E [Program.Main(System.String[])]
Breakpoint 1 hit
eax=00000000 ebx=010feea4 ecx=030e246c edx=00000000 esi=00000000 edi=010fee10
eip=013f007e esp=010fede0 ebp=010fedf8 iopl=0 nv up ei pl zr na pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000246
013f007e 90 nop
ESP 레지스터를 이용해 스택을 조사해 볼까요? ^^
0:000> dd esp
010fede0 00000000 00000000 00000000 00000000
010fedf0 00000000 030e246c 010fee04 72242652
010fee00 01329f38 010fee58 7225264f 010feea4
010fee10 010fee48 72364d4e 010fef84 72252608
010fee20 09ca89e9 010fefdc 010fef40 010feef4
010fee30 00000001 010feea4 00000000 09ca89e9
010fee40 010fee10 00000005 010feff4 723e6e4c
010fee50 7ae04131 00000001 010feed8 72252e95
현재 상태에서 windbg의 disassembly 창(Alt + 7)을 확인하면 eip 레지스터 값이 013f007e이기 때문에 다음과 같은 내용이 나옵니다.
013f007e 90 nop
013f007f b98a4c1a71 mov ecx,offset mscorlib_ni+0x4c8a (711a4c8a)
013f0084 ba02000000 mov edx,2
013f0089 e8b221e7ff call 01262240
013f008e 8945ec mov dword ptr [ebp-14h],eax
013f0091 8b45ec mov eax,dword ptr [ebp-14h]
013f0094 8945f0 mov dword ptr [ebp-10h],eax
013f0097 8b45f0 mov eax,dword ptr [ebp-10h]
013f009a 83780400 cmp dword ptr [eax+4],0
013f009e 7705 ja 013f00a5
013f00a0 e824640e71 call clr!JIT_RngChkFail (724d64c9)
013f00a5 c7400834120000 mov dword ptr [eax+8],1234h
013f00ac 8b45f0 mov eax,dword ptr [ebp-10h]
013f00af 83780401 cmp dword ptr [eax+4],1
013f00b3 7705 ja 013f00ba
013f00b5 e80f640e71 call clr!JIT_RngChkFail (724d64c9)
013f00ba c7400c78560000 mov dword ptr [eax+0Ch],5678h
013f00c1 8b45f0 mov eax,dword ptr [ebp-10h]
그런데, Main 메서드의 시작이 eip=013f007e가 맞을까요? 이를 위해 name2ee로 JIT 번역된 메서드의 주소를 알아봅니다.
0:000> !name2ee ConsoleApplication1 Program.Main
Module: 01272e94
Assembly: ConsoleApplication1.exe
Token: 06000001
MethodDesc: 01273794
Name: Program.Main(System.String[])
JITTED Code Address: 013f0050
아하... 013f007e보다 조금 앞선 013f0050이 진짜 시작 번지군요. 그사이의 역어셈블리 코드는 다음과 같습니다.
013f0050 55 push ebp
013f0051 8bec mov ebp,esp
013f0053 83ec18 sub esp,18h
013f0056 33c0 xor eax,eax
013f0058 8945ec mov dword ptr [ebp-14h],eax
013f005b 8945e8 mov dword ptr [ebp-18h],eax
013f005e 894dfc mov dword ptr [ebp-4],ecx
013f0061 833d6031270100 cmp dword ptr ds:[1273160h],0
013f0068 7405 je 013f006f
013f006a e845700e71 call clr!JIT_DbgIsJustMyCode (724d70b4)
013f006f 33d2 xor edx,edx
013f0071 8955f0 mov dword ptr [ebp-10h],edx
013f0074 33d2 xor edx,edx
013f0076 8955f8 mov dword ptr [ebp-8],edx
013f0079 33d2 xor edx,edx
013f007b 8955f4 mov dword ptr [ebp-0Ch],edx
전형적인 prolog 코드가 나오고, 뒤이어 eax == 0 값으로 지역변수(ebp-14h, ebp-18h)를 초기화하는 코드가 나옵니다.
sub esp, 18h를 했으니, ebp 레지스터에서 18을 빼면 이전에 "dd esp"로 확인한 내용과 동일한 덤프값이 출력됩니다.
0:000> dd (ebp - 18)
010fede0 00000000 00000000 00000000 00000000
010fedf0 00000000 030e246c 010fee04 72242652
010fee00 01329f38 010fee58 7225264f 010feea4
010fee10 010fee48 72364d4e 010fef84 72252608
010fee20 09ca89e9 010fefdc 010fef40 010feef4
010fee30 00000001 010feea4 00000000 09ca89e9
010fee40 010fee10 00000005 010feff4 723e6e4c
010fee50 7ae04131 00000001 010feed8 72252e95
현재 013f007e에서 실행이 멈춘 상태인데요. F10 키를 눌러 명령을 한 라인씩 실행시켜 보겠습니다. 그다음에 실행될 코드를 보면,
013f007e 90 nop
013f007f b98a4c1a71 mov ecx,offset mscorlib_ni+0x4c8a (711a4c8a)
013f0084 ba02000000 mov edx,2
013f0089 e8b221e7ff call 01262240
"call 01262240" 부분이 아마도 new int [] 호출일 것으로 짐작됩니다. 그리고 호출의 반환값은 eax에 저장될 것이고 그 주소는 GC 힙의 객체 주소일 것입니다.
그다음 코드를 실행해 보면,
013f008e 8945ec mov dword ptr [ebp-14h],eax
ebp-14h의 지역 변수 위치에 반환받은 eax 값을 넣게 됩니다. arr1 = [new 로 할당받은 주소]에 해당하는 코드입니다. 그렇게 하고 스택 덤프를 다시 뜨면,
0:000> dd esp
010fede0 00000000 030e247c 00000000 00000000
010fedf0 00000000 030e246c 010fee04 72242652
010fee00 01329f38 010fee58 7225264f 010feea4
010fee10 010fee48 72364d4e 010fef84 72252608
010fee20 09ca89e9 010fefdc 010fef40 010feef4
010fee30 00000001 010feea4 00000000 09ca89e9
010fee40 010fee10 00000005 010feff4 723e6e4c
010fee50 7ae04131 00000001 010feed8 72252e95
030e247c 값이 ebp-14h에 위치합니다. 그다음엔 당연히 arr2 = arr1; 코드와 대응되겠지요.
013f0091 8b45ec mov eax,dword ptr [ebp-14h]
013f0094 8945f0 mov dword ptr [ebp-10h],eax
(디버그 버전이라 그런지) arr1의 값을 eax에 넣고, 다시 그 값을 arr2(ebp-10h)로 넣고 있습니다. 이 시점에 스택 덤프를 뜨면 예상했던 대로 arr2 변수의 위치에 arr1의 객체 주소가 들어가 있는 것을 확인할 수 있습니다.
0:000> dd esp
010fede0 00000000 030e247c 030e247c 00000000
010fedf0 00000000 030e246c 010fee04 72242652
010fee00 01329f38 010fee58 7225264f 010feea4
010fee10 010fee48 72364d4e 010fef84 72252608
010fee20 09ca89e9 010fefdc 010fef40 010feef4
010fee30 00000001 010feea4 00000000 09ca89e9
010fee40 010fee10 00000005 010feff4 723e6e4c
010fee50 7ae04131 00000001 010feed8 72252e95
정말 030e247c 주소가 GC 힙의 배열 객체 주소일까요? 확인을 해보면,
0:000> !do 030e247c
Name: System.Int32[]
MethodTable: 7159c738
EEClass: 7120c0c0
Size: 20(0x14) bytes
Array: Rank 1, Number of elements 2, Type Int32
Fields:
None
0:000> !da -details 30e247c
Name: System.Int32[]
MethodTable: 7159c738
EEClass: 7120c0c0
Size: 20(0x14) bytes
Array: Rank 1, Number of elements 2, Type Int32
Element Methodtable: 7159c770
[0] 030e2484
Name: System.Int32
MethodTable: 7159c770
EEClass: 7120c078
Size: 12(0xc) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
7159c770 400044f 0 System.Int32 1 instance 0 m_value
[1] 030e2488
Name: System.Int32
MethodTable: 7159c770
EEClass: 7120c078
Size: 12(0xc) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
7159c770 400044f 0 System.Int32 1 instance 0 m_value
2개의 int32 요소가 배열에 있는 것을 확인할 수 있고, 확인 방법은 dd를 사용합니다.
0:000> dd 030e247c
030e247c 7159c738 00000002 00000000 00000000
030e248c 00000000 00000000 00000000 00000000
030e249c 00000000 00000000 00000000 00000000
030e24ac 00000000 00000000 00000000 00000000
030e24bc 00000000 00000000 00000000 00000000
030e24cc 00000000 00000000 00000000 00000000
030e24dc 00000000 00000000 00000000 00000000
030e24ec 00000000 00000000 00000000 00000000
위의 값을 해석하면 다음과 같습니다.
MT: 7159c738
배열 요소 수: 00000002
첫 번째 배열 값: 00000000
두 번째 배열 값: 00000000
코드에서는 "int [] arr1 = new int[2] { 0x1234, 0x5678 };"라고 초기화를 했는데 2개의 배열 요소 값은 여전히 0입니다. 왜냐하면 아직도 초기화 코드가 수행되지 않았기 때문입니다.
이제 초기화 코드를 보면, 왜 관리 코드가 네이티브 코드보다 느릴 수밖에 없는지 이유가 나옵니다.
// 배열 요소 첫 번째의 Range Check 수행 후 1234 값 할당
013f009a 83780400 cmp dword ptr [eax+4],0
013f009e 7705 ja 013f00a5
013f00a0 e824640e71 call clr!JIT_RngChkFail (724d64c9)
013f00a5 c7400834120000 mov dword ptr [eax+8],1234h
013f00ac 8b45f0 mov eax,dword ptr [ebp-10h]
// 배열 요소 두 번째의 Range Check 수행 후 1234 값 할당
013f00af 83780401 cmp dword ptr [eax+4],1
013f00b3 7705 ja 013f00ba
013f00b5 e80f640e71 call clr!JIT_RngChkFail (724d64c9)
013f00ba c7400c78560000 mov dword ptr [eax+0Ch],5678h
013f00c1 8b45f0 mov eax,dword ptr [ebp-10h]
아시겠지요? ^^ 요소 접근마다 JIT_RngChkFail 메서드를 호출해서 인덱스 번호가 적절한지 확인하기 때문입니다. C++이었다면 마지막 2개의 mov 코드만 있었을 텐데 "관리 환경"이기 때문에 cmp, ja, call 호출에 따른 오버헤드가 있습니다.
그래도, 진정한 성능 비교를 위해서라면 릴리스 버전을 확인하지 않을 수 없습니다. ^^
위의 소스 코드가 빌드된 어셈블리 코드를 확인하면 최적화 덕분에 훨씬 간결해졌습니다.
02aa0050 55 push ebp
02aa0051 8bec mov ebp,esp
02aa0053 b98a4c1a71 mov ecx,offset mscorlib_ni+0x4c8a (711a4c8a)
02aa0058 ba02000000 mov edx,2
02aa005d e8de2159fe call 01032240
02aa0062 83780400 cmp dword ptr [eax+4],0
02aa0066 7625 jbe 02aa008d
02aa0068 c7400834120000 mov dword ptr [eax+8],1234h
02aa006f 83780401 cmp dword ptr [eax+4],1
02aa0073 7618 jbe 02aa008d
02aa0075 c7400c78560000 mov dword ptr [eax+0Ch],5678h
02aa007c e82b4d0b6f call mscorlib_ni+0x9b4dac (71b54dac)
02aa0081 8bc8 mov ecx,eax
02aa0083 8b01 mov eax,dword ptr [ecx]
02aa0085 8b402c mov eax,dword ptr [eax+2Ch]
02aa0088 ff501c call dword ptr [eax+1Ch]
02aa008b 5d pop ebp
02aa008c c3 ret
02aa008d e83764a36f call clr!JIT_RngChkFail (724d64c9)
02aa0092 cc int 3
JIT_RngChkFail 메서드 호출에 대한 부담은 없어졌지만, 여전히 스택 변수(eax + 8, eax + 0c)에 대한 값을 확인하고 있습니다. 당연히 Native C/C++ 환경에서는 포함되지 않는 부분입니다.
하지만, 꼭 느리다고 실망할 필요는 없습니다. 좀 더 안정적으로 동작하기 위한 보조적인 코드이기 때문에, 어찌 생각해 보면 C/C++로 코딩을 하더라도 해야 될 작업이었을지도 모릅니다. 이 정도 오버헤드는, 안정성이 더 중요한 mission-critical한 프로그램에서는 충분히 감안할 수 있지 않을까요? ^^
그리고 나름대로는 JIT 컴파일 시에 대상 컴퓨터의 환경에 장착된 CPU에 최적화된 코드를 사용한다고 하니... 시간이 지남에 따라 "공짜 점심(Free Lunch)"를 즐길 수도 있을 것입니다.
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]