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

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://technet.microsoft.com/en-us/sysinternals/handle.aspx

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

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일 것입니다.

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




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





[최초 등록일: ]
[최종 수정일: 7/13/2017 ]

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

비밀번호

댓글 쓴 사람
 




... 31  32  33  34  35  36  37  [38]  39  40  41  42  43  44  45  ...
NoWriterDateCnt.TitleFile(s)
11282정성태9/11/20174433Math: 22. 행렬로 바라보는 피보나치 수열
11281정성태8/26/20174433.NET Framework: 677. Visual Studio 2017 - NuGet 패키지를 직접 참조하는 PackageReference 지원
11280정성태8/24/20173217디버깅 기술: 94. windbg - 풀 덤프에 포함된 모든 모듈을 파일로 저장하는 방법
11279정성태8/23/20177968.NET Framework: 676. C# Thread가 Running 상태인지 아는 방법
11278정성태8/23/20173662오류 유형: 417. TFS - Warning - Unable to refresh ... because you have a pending edit. [1]
11277정성태8/23/20174510오류 유형: 416. msbuild - error MSB4062: The "TransformXml" task could not be loaded from the assembly
11276정성태8/23/20176121.NET Framework: 675. C# - 확장자와 연결된 실행 파일 경로 찾기 [2]파일 다운로드1
11275정성태8/23/20179517개발 환경 구성: 323. Visual Studio 설치 없이 빌드 환경 구성 - Visual Studio 2017용 Build Tools
11274정성태8/22/20173885.NET Framework: 674. Thread 타입의 Suspend/Resume/Join 사용 관련 예외 처리
11273정성태8/22/20175970오류 유형: 415. 윈도우 업데이트 에러 Error 0x80070643
11272정성태8/21/20176632VS.NET IDE: 120. 비주얼 스튜디오 2017 버전 15.3.1 - C# 7.1 공개 [2]
11271정성태8/19/20173476VS.NET IDE: 119. Visual Studio 2017에서 .NET Core 2.0 프로젝트 환경 구성하는 방법
11270정성태4/20/201810098.NET Framework: 673. C#에서 enum을 boxing 없이 int로 변환하기 [2]
11269정성태8/17/20174066디버깅 기술: 93. windbg - 풀 덤프에서 .NET 스레드의 상태를 알아내는 방법
11268정성태8/14/20173987디버깅 기술: 92. windbg - C# Monitor Lock을 획득하고 있는 스레드 찾는 방법
11267정성태8/10/20175161.NET Framework: 672. 모노 개발 환경
11266정성태8/10/20174446.NET Framework: 671. C# 6.0 이상의 소스 코드를 Visual Studio 설치 없이 명령행에서 컴파일하는 방법
11265정성태2/25/201920967기타: 66. 도서: 시작하세요! C# 7.1 프로그래밍: 기본 문법부터 실전 예제까지 [11]
11264정성태8/9/20174359오류 유형: 414. UWP app을 signtool.exe로 서명 시 0x8007000b 오류 발생
11263정성태8/9/20174178오류 유형: 413. The C# project "..." is targeting ".NETFramework, Version=v4.0", which is not installed on this machine. [3]
11262정성태8/5/20174030오류 유형: 412. windbg - SOS does not support the current target architecture. [3]
11261정성태8/1/20183896디버깅 기술: 91. windbg - 풀 덤프 파일로부터 강력한 이름의 어셈블리 추출 후 사용하는 방법
11260정성태8/3/20173866.NET Framework: 670. C# - 실행 파일로부터 공개키를 추출하는 방법
11259정성태8/2/20173528.NET Framework: 669. 지연 서명된 어셈블리를 sn.exe -Vr 등록 없이 사용하는 방법
11258정성태8/1/20174183.NET Framework: 668. 지연 서명된 DLL과 서명된 DLL의 차이점파일 다운로드1
11257정성태7/31/20174223.NET Framework: 667. bypassTrustedAppStrongNames 옵션 설명파일 다운로드1
... 31  32  33  34  35  36  37  [38]  39  40  41  42  43  44  45  ...