Microsoft MVP성태의 닷넷 이야기
오류 유형: 408. SqlConnection 객체 생성 시 무한 대기 문제 [링크 복사], [링크+제목 복사],
조회: 19455
글쓴 사람
정성태 (techsharer at outlook.com)
홈페이지
첨부 파일

SqlConnection 객체 생성 시 무한 대기 문제

고객사 닷넷 프로그램이 어느 순간부터 무한 대기 상태에 빠지며 종료가 안 된다는 보고가 왔습니다.

해당 프로그램을 개발한 측에서 나름 분석을 시도하며 프로세스 덤프도 뜨고 DebugDiag 분석을 돌린 것도 함께 보내주었는데요. 무한 대기의 원인은 다음과 같이 SqlConnection.Open에서 Mutex 획득을 시도했기 때문입니다.

[Managed to Native Transition]  
System.dll!System.Diagnostics.SharedUtils.SafeWaitForMutexOnce(System.Threading.Mutex mutexIn, ref System.Threading.Mutex mutexOut) Line 263    C#
System.dll!System.Diagnostics.SharedUtils.SafeWaitForMutex(System.Threading.Mutex mutexIn, ref System.Threading.Mutex mutexOut) Line 240    C#
System.dll!System.Diagnostics.SharedUtils.EnterMutexWithoutGlobal(string mutexName, ref System.Threading.Mutex mutex) Line 88   C#
System.dll!System.Diagnostics.SharedPerformanceCounter.GetCounter(string counterName, string instanceName, bool enableReuse, System.Diagnostics.PerformanceCounterInstanceLifetime lifetime) Line 715   C#
System.dll!System.Diagnostics.SharedPerformanceCounter.SharedPerformanceCounter(string catName, string counterName, string instanceName, System.Diagnostics.PerformanceCounterInstanceLifetime lifetime) Line 68    C#
System.dll!System.Diagnostics.PerformanceCounter.InitializeImpl() Line 247  C#
System.dll!System.Diagnostics.PerformanceCounter.RawValue.set(long value) Line 478  C#
System.Data.dll!System.Data.ProviderBase.DbConnectionPoolCounters.Counter.Counter(string categoryName, string instanceName, string counterName, System.Diagnostics.PerformanceCounterType counterType)  Unknown
System.Data.dll!System.Data.ProviderBase.DbConnectionPoolCounters.DbConnectionPoolCounters(string categoryName, string categoryHelp)    Unknown
System.Data.dll!System.Data.SqlClient.SqlPerformanceCounters.SqlPerformanceCounters()   Unknown
System.Data.dll!System.Data.SqlClient.SqlPerformanceCounters.SqlPerformanceCounters()   Unknown
[Native to Managed Transition]  
[Managed to Native Transition]  
System.Data.dll!System.Data.SqlClient.SqlConnectionFactory.SqlConnectionFactory()   Unknown
[Native to Managed Transition]  
[Managed to Native Transition]  
System.Data.dll!System.Data.SqlClient.SqlConnection.SqlConnection() Unknown
[Native to Managed Transition]  
[Managed to Native Transition]  
System.Data.dll!System.Data.SqlClient.SqlConnection.SqlConnection() Unknown
ConsoleApplication1.exe!ConsoleApplication1.Program.Main(string[] args) Line 22 C#

상황은 간단합니다. SqlConnection 생성자부터 .NET Reflector 등을 이용해 코드를 확인해 보면, 내부적으로 성능 카운터(Performance Counter)를 초기화하는데 그 과정에서 시스템 전역적인 Mutex로 동기화가 이뤄지는 것입니다. 이런 경우 mutex 이름만 알아내면 이것을 재현해 볼 수 있는데, 역시 .NET Reflector 등을 이용해 조사하면 ".net data provider for sqlserver"라는 이름임을 알 수 있습니다.

따라서, 재현을 위해 다음과 같이 스레드 하나에서 Mutex를 열고, 다른 스레드에서는 SqlConnection 객체를 생성해 보면 됩니다.

using System;
using System.Data.SqlClient;
using System.Security.AccessControl;
using System.Security.Principal;
using System.Threading;

class Program
{
    static EventWaitHandle _ewh = new EventWaitHandle(false, EventResetMode.ManualReset);
    static void Main(string[] args)
    {
        Thread t1 = new Thread(threadFunc);
        t1.Start();

        _ewh.WaitOne();

        Console.WriteLine("Opening DB Connection...");
        SqlConnection con = new SqlConnection(); // SqlConnection 객체 생성
        Console.WriteLine("Opened");
    }

    private static void threadFunc()
    {
        string mutexName = "Global\\.net data provider for sqlserver";

        bool flag;
        MutexSecurity mutexSecurity = new MutexSecurity();
        SecurityIdentifier identity = new SecurityIdentifier(WellKnownSidType.AuthenticatedUserSid, null);
        mutexSecurity.AddAccessRule(new MutexAccessRule(identity, MutexRights.Synchronize | MutexRights.Modify, AccessControlType.Allow));
        using (Mutex mutex = new Mutex(false, mutexName, out flag, mutexSecurity))
        {
            Console.WriteLine("Enter of MUTEX");
            mutex.WaitOne();
            _ewh.Set();

            Thread.Sleep(-1); // mutex 해제 없이 무한 대기
            mutex.ReleaseMutex();
        }
        Console.WriteLine("Exit of MUTEX");
    }
}

이 프로그램을 실행한 화면 출력은,

Enter of MUTEX
Opening DB Connection...

"Global\\.net data provider for sqlserver" 이름의 mutex가 해제되지 않는 것으로 인해 SqlConnection 생성자가 수행이 완료되지 않고 있는 것을 보여줍니다.

정리해 보면, 고객사의 경우 어떤 식으로든 해당 mutex를 열고 있는 프로그램이 있다는 이야기가 됩니다.

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




그런데, 왜? 이런 일이 발생했을까요? 100% 장담할 수는 없지만, 최근 그 고객사는 DB 관련 모니터링 프로그램을 설치했다는 차이만 있었습니다. 물론, 그 프로그램 때문이라고 어설프게 말해서는 안 됩니다. ^^

이런 상황에서 정확한 원인을 식별하려면, 해당 문제가 발생했을 때 Sysinternals의 handle.exe 프로그램을 사용해서 확인할 수 있습니다.

sysinternals - handle.exe
; https://learn.microsoft.com/en-us/sysinternals/downloads/handle

대략 다음과 같은 식으로 실행해서 그 순간에 열린 모든 프로세스 별 핸들 목록을 보관해 둡니다.

handle.exe -a > report.log

그런 다음 그 파일을 대상으로 검색을 해보면,

findstr /I /c:".net data provider for sqlserver" report.log

출력 결과는 대충 이렇습니다.

 145C: Key           HKLM\SYSTEM\ControlSet001\Services\.NET Data Provider for SqlServer\Performance
 1460: Mutant        \Sessions\1\BaseNamedObjects\.NET Data Provider for SqlServer_Perf_Library_Lock_PID_41c8
 2B68: Section       \BaseNamedObjects\netfxcustomperfcounters.1.0.net data provider for sqlserver
  2B4: Mutant        \BaseNamedObjects\.net data provider for sqlserver
  2B8: Section       \BaseNamedObjects\netfxcustomperfcounters.1.0.net data provider for sqlserver
  2C4: Mutant        \BaseNamedObjects\.net data provider for sqlserver

해당 목록에서 "\BaseNamedObjects\.net data provider for sqlserver" 문자열을 포함하고 Mutant로 식별된 핸들을 추리면 2개로 문제가 좁혀집니다.

  2B4: Mutant        \BaseNamedObjects\.net data provider for sqlserver
  2C4: Mutant        \BaseNamedObjects\.net data provider for sqlserver

다시 report.log 파일을 열어 위의 핸들을 검색하면 어느 프로세스에 속해 있는지 나옵니다. 그중의 하나는 고객사의 pid일 것이고, 나머지 하나는 문제를 유발한 프로그램의 pid일 것입니다.

(그런데, 해당 문제가 한 달에 한번 정도 간헐적으로 발생한다고 하니... 원인 찾기가 그리 녹록치는 않을 것 같습니다. ^^)




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







[최초 등록일: ]
[최종 수정일: 11/5/2022]

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

비밀번호

댓글 작성자
 




... 181  182  [183]  184  185  186  187  188  189  190  191  192  193  194  195  ...
NoWriterDateCnt.TitleFile(s)
393정성태11/8/200619530오류 유형: 17. Unable to start debugging - The binding handle is invalid.
371정성태10/23/200618689오류 유형: 16. STS Communication failed.
370정성태11/12/200622597.NET Framework: 75. Windows CardSpace 이야기 (이 글의 내용은 재작성되어질 예정입니다.)
375정성태10/25/200624577    답변글 .NET Framework: 75.1. 개인 발행 카드에 대한 Microsoft 예제 실습(이 글의 내용은 재작성되어질 예정입니다.)
376정성태10/27/200624198    답변글 .NET Framework: 75.2. "Windows CardSpace"와 "인증서 서비스"의 만남(이 글의 내용은 재작성되어질 예정입니다.)
377정성태10/26/200623845    답변글 .NET Framework: 75.3. Managed Card 발행에 대한 Microsoft 예제 실습 (1) - CardWriter (이 글의 내용은 재작성되어질 예정입니다.)
385정성태11/6/200626467    답변글 .NET Framework: 75.4. Managed Card 발행에 대한 Microsoft 예제 실습 (2) - STS 구현 (이 글의 내용은 재작성되어질 예정입니다.) [7]
387정성태11/2/200627228    답변글 .NET Framework: 75.5. Windows CardSpace와 SYSNET 사이트의 만남 (이 글의 내용은 재작성되어질 예정입니다.) [1]
397정성태11/11/200624769    답변글 .NET Framework: 75.6. CardWriter.csproj와 함께 알아보는 인증서 식별 방법(이 글의 내용은 재작성되어질 예정입니다.)
398정성태11/12/200623284    답변글 .NET Framework: 75.7. 카드에 암호 거는 방법(이 글의 내용은 재작성되어질 예정입니다.)
399정성태11/12/200625524    답변글 .NET Framework: 75.8. 인증서/스마트 카드에 기반한 Managed Card - STS 구현(이 글의 내용은 재작성되어질 예정입니다.) [5]
369정성태10/22/200621016오류 유형: 15. 자동 업데이트 실패
367정성태10/22/200636797Windows: 3. IIS 7.0 다중 바인딩 설정하는 방법 [1]
365정성태10/21/200620502Windows: 2. 서버(build 5600)에 IIS 7.0 서비스와 .NET 3.0 설치 방법
359정성태10/17/200616664오류 유형: 14. VS.NET 빌드 오류 - FxCopCmd.exe returned error code 65.
358정성태10/17/200621866오류 유형: 13. WSE 3.0 서비스 관련 WSE101 오류 / Destination Unreachable
357정성태12/1/200624119.NET Framework: 74. WCF 이야기 [4]
378정성태10/28/200628886    답변글 .NET Framework: 74.1. WCF와 WSE 3.0의 활용 [4]파일 다운로드1
379정성태11/3/200627845    답변글 .NET Framework: 74.2. WCF로 구현하는 .NET Remoting [4]파일 다운로드1
380정성태10/28/200626746    답변글 .NET Framework: 74.3. 웹 서비스와 닷넷 리모팅으로써의 WCF 구현파일 다운로드1
381정성태10/28/200629184    답변글 .NET Framework: 74.4. WCF 서비스 참조 추가 메뉴 [2]
382정성태10/28/200635248    답변글 .NET Framework: 74.5. WCF 서비스를 IIS에서 호스팅하는 방법파일 다운로드1
383정성태10/28/200630007    답변글 .NET Framework: 74.6. IIS 6.0: 다중 Endpoint 제공파일 다운로드1
384정성태10/28/200626915    답변글 .NET Framework: 74.7. IIS 7.0: 다중 Endpoint 제공
389정성태11/11/200629707    답변글 .NET Framework: 74.8. WCF에 SSL 적용 (1) - Httpcfg.exe 도구를 이용한 SSL 설정
390정성태11/6/200626890    답변글 .NET Framework: 74.9. WCF에 SSL 적용 (2) - 서비스 제작파일 다운로드1
... 181  182  [183]  184  185  186  187  188  189  190  191  192  193  194  195  ...