NT 서비스의 Main 메서드 안에서 Process.GetProcessesByName 호출 시 멈춤 현상
일반적으로 NT 서비스는 다음과 같은 식으로 만듭니다.
public class Service1 : System.ServiceProcess.ServiceBase
{
static void Main()
{
System.ServiceProcess.ServiceBase[] ServicesToRun =
new System.ServiceProcess.ServiceBase[] { new Service1() };
System.ServiceProcess.ServiceBase.Run(ServicesToRun);
}
private void InitializeComponent()
{
this.ServiceName = "Service1";
}
protected override void OnStart(string[] args)
{
// 서비스 코드 작성 (예를 들어, WCF Open)
}
protected override void OnStop()
{
}
}
그런데, 제 경우에 Main 메서드에서 ServiceBase.Run을 호출하기 전에 약간의 초기화 작업이 필요해서 다음과 같은 코드를 넣었습니다.
Process[] processes = Process.GetProcesses(...);
[또는]
Process[] processes = Process.GetProcessesByName(...);
이렇게 놓고 테스트를 하는데, 5대의 VM 중에서 4대에서는 정상적으로 되고 1대에서만 Process.GetProcessesByName에서 스레드가 블록되어 버리고, SCM(Service Control Manager)은 일정 시간 동안 NT 서비스가 실행을 반환하지 않으므로 중간에 서비스를 강제 종료해버렸습니다.
Windows Server 2003 x86 SP2(.NET 2.0 ~ .NET 4.0 설치): 정상 동작
Windows Server 2003 x64 SP2(.NET 2.0 ~ .NET 4.0 설치): 정상 동작
Windows Server 2008 x86 SP2(.NET 2.0 ~ .NET 4.0 설치): 정상 동작
Windows Server 2008 R2 SP1(.NET 2.0 ~ .NET 4.0 설치): 정상 동작
Windows Server 2003 x86 SP2(.NET 1.1): Hang 현상 발생
원인을 찾기 위해 procdump를 이용해 hang 걸린 상태에서 풀 덤프를 받고,
procdump -ma [... pid ...]
"Debug Diagnostic Tool"를 이용해 분석해 보았습니다. (1.2 버전부터 많이 좋아져서 ^^ 이것 때문에 windbg 실행할 일이 많이 줄었습니다. ^^)
Debug Diagnostic Tool v1.2
; http://www.microsoft.com/en-us/download/details.aspx?id=26798
결과는 다음과 같습니다.
Thread 0 - System ID 468
This thread is making an outbound RPC call over LPC to the local machine.
.NET Call Stack
Function
[DEFAULT] I4 Microsoft.Win32.UnsafeNativeMethods.RegQueryValueEx(ValueClass System.Runtime.InteropServices.HandleRef,String,SZArray I4,SZArray I4,ValueClass System.Runtime.InteropServices.HandleRef,ByRef I4)
[hasThis] I System.Diagnostics.PerformanceMonitor.GetData(String)
[hasThis] I System.Diagnostics.PerformanceCounterLib.GetPerformanceData(String)
[hasThis] Class System.Collections.Hashtable System.Diagnostics.PerformanceCounterLib.get_CategoryTable()
[hasThis] I System.Diagnostics.PerformanceCounterLib.GetPerformanceData(SZArray String,SZArray I4)
Full Call Stack
Function Source
ntdll!KiFastSystemCallRet
ntdll!ZwRequestWaitReplyPort+c
rpcrt4!LRPC_CCALL::SendReceive+230
rpcrt4!I_RpcSendReceive+24
rpcrt4!NdrSendReceive+2b
rpcrt4!NdrClientCall2+22e
advapi32!RStartServiceW+1c
advapi32!StartServiceW+1e
wmiaprpl!WmiAdapterWrapper::Open+8d
advapi32!OpenExtObjectLibrary+699
advapi32!QueryExtensibleData+473
advapi32!PerfRegQueryValue+536
advapi32!LocalBaseRegQueryValue+306
advapi32!RegQueryValueExW+96
0x009ca8ad
[DEFAULT] [hasThis] I System.Diagnostics.PerformanceCounterLib.GetPerformanceData(String)
[DEFAULT] [hasThis] Class System.Collections.Hashtable System.Diagnostics.PerformanceCounterLib.get_CategoryTable()
[DEFAULT] [hasThis] I System.Diagnostics.PerformanceCounterLib.GetPerformanceData(SZArray String,SZArray I4)
[DEFAULT] SZArray Class System.Diagnostics.ProcessInfo System.Diagnostics.NtProcessManager.GetProcessInfos(Class System.Diagnostics.PerformanceCounterLib)
[DEFAULT] SZArray Class System.Diagnostics.ProcessInfo System.Diagnostics.NtProcessManager.GetProcessInfos(String,Boolean)
[DEFAULT] SZArray Class System.Diagnostics.ProcessInfo System.Diagnostics.ProcessManager.GetProcessInfos(String)
mscorwks!CallDescrWorker+30
mscorwks!MethodDesc::CallDescr+1b8
mscorwks!MethodDesc::CallDescr+4f
mscorwks!MethodDesc::Call+97
mscorwks!ClassLoader::CanAccess+1d6
mscorwks!ClassLoader::ExecuteMainMethod+49d
mscorwks!Assembly::ExecuteMainMethod+21
mscorwks!SystemDomain::ExecuteMainMethod+421
mscorwks!ExecuteEXE+1ce
mscorwks!_CorExeMain+59
mscoree!_CorExeMain+2c
kernel32!BaseProcessStart+23
Outbound RPC Call:
Protocol Sequence ncalrpc
Endpoint ntsvcs
처음에는 콜 스택이 눈에 잘 안들어와서 문제가 뭔지 몰랐는데, 마지막의 LPC Endpoint 정보에 ntsvcs가 있는 것을 보고 이것이 뭔지 찾아봐야만 했습니다.
Well-known MSRPC named pipes
; http://www.hsc.fr/ressources/articles/win_net_srv/well_known_named_pipes.html
위의 웹 페이지에 보면, ntsvcs에 대해 다음과 같은 정보를 찾을 수 있습니다.
Named pipe: svcctl (ntsvcs alias)
Description: svcctl interface (Services control manager)
Service or process: services.exe
Interface identifier: 367aeb81-9844-35f1-ad32-98f038001003 v2.0
다시 svcctl 정보를 파고 들어가면 다음의 API가 눈에 띕니다.
Interface: 367aeb81-9844-35f1-ad32-98f038001003 v2.0: svcctl
Operation number: 0x13
Operation name: StartServiceW
Windows API: StartService
아하... 이제야 이해가 되는군요.
대강 짐작되는 바는 이렇습니다. Main 메서드에서 Process.GetProcessesByName을 호출했더니, 이것은 내부적으로 System.Diagnostics.PerformanceCounterLib.GetPerformanceData를 부릅니다. 성능 카운터 접속은 내부적으로 SCM에게 또 다른 서비스를 시작하라는 "
advapi32!StartServiceW" Win32 API를 호출하였고 이것이 LPC 호출로 SCM 프로세스(services.exe)에게 전달된 것입니다.
그 순간에, SCM 프로세스는 이미 Process.GetProcessesByName을 호출한 서비스가 완료되기를 기다리고 있기 때문에 dead-lock 상태에 빠져 버린 것입니다.
그런데, 어떤 서비스를 시작시키려고 그랬던 것일까요? 그냥 감이 옵니다. ^^ 콜스택에 보니 "wmiaprpl!WmiAdapterWrapper"라는 정보로 봐서 아마도 WMI가 아닐까 싶었는데, 의외로 이미 해당 서비스(Winmgmt: Windows Management Instrumentation)는 실행된 상태입니다.
그래도 혹시나 싶어, 정상 동작하던 동일한 운영체제의 Windows Server 2003에서 일부러 WMI 서비스를 정지시키고 테스트를 해보니 정말로 hang 현상이 발생했습니다. ^^
마찬가지로 .NET에서 성능 카운터 호출로 연결되는 또 다른 기능을 사용해도 (가령: Process.GetCurrentProcess().VirtualMemorySize) 동일한 현상이 재현되었고.
문제를 정리해 보면, 결국 StartServiceW 메서드의 호출을 발생시킨 부모 API 중에서 WMI에 의존하도록 만든 호출이 있다는 것입니다.
advapi32!StartServiceW+1e
wmiaprpl!WmiAdapterWrapper::Open+8d
advapi32!OpenExtObjectLibrary+699
advapi32!QueryExtensibleData+473
advapi32!PerfRegQueryValue+536
advapi32!LocalBaseRegQueryValue+306
advapi32!RegQueryValueExW+96
2대의 PC에서 advapi32.dll을 비교해 보니, 잘 되던 2003 서버는 "5.2.3790.4555"이고 hang 현상이 발생했던 2003 서버는 "5.2.3790.4455"으로 다르긴 합니다.
결국, 정상적으로 윈도우 업데이트가 안되던 운영체제가 문제였던 것입니다.
휴~~~ 이래서 테스트 장비는 다양해야 합니다. ^^
그러고 보니, 해결 방법을 빼놓았군요. 그냥 초기화 코드를 Main 메서드가 아닌 Service 클래스의 OnStart로 옮기는 것으로 간단하게 마무리 했습니다.
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]