Microsoft MVP성태의 닷넷 이야기
오류 유형: 408. SqlConnection 객체 생성 시 무한 대기 문제 [링크 복사], [링크+제목 복사],
조회: 12200
글쓴 사람
정성태 (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

비밀번호

댓글 작성자
 




... 16  17  18  19  20  21  22  23  24  25  26  27  28  [29]  30  ...
NoWriterDateCnt.TitleFile(s)
12909정성태1/10/20228150오류 유형: 782. Visual Studio 2022 설치 시 "Couldn't install Microsoft.VisualCpp.Redist.14.Latest"
12908정성태1/10/20225986.NET Framework: 1132. C# - ref/out 매개변수의 IL 코드 처리
12907정성태1/9/20226512오류 유형: 781. (youtube-dl.exe) 실행 시 "This app can't run on your PC" / "Access is denied." 오류 발생
12906정성태1/9/20227125.NET Framework: 1131. C# - 네임스페이스까지 동일한 타입을 2개의 DLL에서 제공하는 경우 충돌을 우회하는 방법 [1]파일 다운로드1
12905정성태1/8/20226792오류 유형: 780. Could not load file or assembly 'Microsoft.VisualStudio.TextTemplating.VSHost.15.0, Version=16.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a' or one of its dependencies.
12904정성태1/8/20228780개발 환경 구성: 623. Visual Studio 2022 빌드 환경을 위한 github Actions 설정 [1]
12903정성태1/7/20227376.NET Framework: 1130. C# - ELEMENT_TYPE_INTERNAL 유형의 사용 예
12902정성태1/7/20227432오류 유형: 779. SQL 서버 로그인 에러 - provider: Shared Memory Provider, error: 0 - No process is on the other end of the pipe.
12901정성태1/5/20227459오류 유형: 778. C# - .NET 5+에서 warning CA1416: This call site is reachable on all platforms. '...' is only supported on: 'windows' 경고 발생
12900정성태1/5/20229153개발 환경 구성: 622. vcpkg로 ffmpeg를 빌드하는 경우 생성될 구성 요소 제어하는 방법
12899정성태1/3/20228644개발 환경 구성: 621. windbg에서 python 스크립트 실행하는 방법 - pykd (2)
12898정성태1/2/20229214.NET Framework: 1129. C# - ffmpeg(FFmpeg.AutoGen)를 이용한 비디오 인코딩 예제(encode_video.c) [1]파일 다운로드1
12897정성태1/2/20228041.NET Framework: 1128. C# - 화면 캡처한 이미지를 ffmpeg(FFmpeg.AutoGen)로 동영상 처리 [4]파일 다운로드1
12896정성태1/1/202210945.NET Framework: 1127. C# - FFmpeg.AutoGen 라이브러리를 이용한 기본 프로젝트 구성파일 다운로드1
12895정성태12/31/20219404.NET Framework: 1126. C# - snagit처럼 화면 캡처를 연속으로 수행해 동영상 제작 [1]파일 다운로드1
12894정성태12/30/20217367.NET Framework: 1125. C# - DefaultObjectPool<T>의 IDisposable 개체에 대한 풀링 문제 [3]파일 다운로드1
12893정성태12/27/20218963.NET Framework: 1124. C# - .NET Platform Extension의 ObjectPool<T> 사용법 소개파일 다운로드1
12892정성태12/26/20216966기타: 83. unsigned 형의 이전 값이 최댓값을 넘어 0을 지난 경우, 값의 차이를 계산하는 방법
12891정성태12/23/20216886스크립트: 38. 파이썬 - uwsgi의 --master 옵션
12890정성태12/23/20217014VC++: 152. Golang - (문자가 아닌) 바이트 위치를 반환하는 strings.IndexRune 함수
12889정성태12/22/20219419.NET Framework: 1123. C# - (SharpDX + DXGI) 화면 캡처한 이미지를 빠르게 JPG로 변환하는 방법파일 다운로드1
12888정성태12/21/20217546.NET Framework: 1122. C# - ImageCodecInfo 사용 시 System.Drawing.Image와 System.Drawing.Bitmap에 따른 Save 성능 차이파일 다운로드1
12887정성태12/21/20219658오류 유형: 777. OpenCVSharp4를 사용한 프로그램 실행 시 "The type initializer for 'OpenCvSharp.Internal.NativeMethods' threw an exception." 예외 발생
12886정성태12/20/20217551스크립트: 37. 파이썬 - uwsgi의 --enable-threads 옵션 [2]
12885정성태12/20/20217808오류 유형: 776. uwsgi-plugin-python3 환경에서 MySQLdb 사용 환경
12884정성태12/20/20216855개발 환경 구성: 620. Windows 10+에서 WMI root/Microsoft/Windows/WindowsUpdate 네임스페이스 제거
... 16  17  18  19  20  21  22  23  24  25  26  27  28  [29]  30  ...