ADO.NET 연결 풀 고갈로 인한 ASP.NET Core 웹 응용 프로그램 응답 없음 문제 분석

1. 배경

올해 초, 한 개발자로부터 관리 시스템이 응답하지 않는 문제가 발생했다는 연락을 받았습니다. 덤프 파일을 받아 분석을 시작했습니다.

2. 응답 없음의 원인 분석

2.1 스레드 풀 큐 적체 확인

웹 시스템의 무응답 문제를 진단할 때 가장 먼저 확인해야 할 것은 스레드 풀입니다. !sos tpq 명령어를 사용하여 스레드 풀 큐 상태를 확인했습니다.

0:000> !sos tpq
global work item queue________________________________
0x00000004010774C0 Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT<Microsoft.AspNetCore.Hosting.HostingApplication+Context>
0x0000000401077808 Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT<Microsoft.AspNetCore.Hosting.HostingApplication+Context>
....
0x000000030239DD78 Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT<Microsoft.AspNetCore.Hosting.HostingApplication+Context>
0x000000030239E0C0 Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT<Microsoft.AspNetCore.Hosting.HostingApplication+Context>

local per thread work items_____________________________________
0x0000000100A46410 System.Threading.Tasks.Task<System.Threading.Tasks.Task>
...
0x000000010133F8C0 System.Threading.Tasks.Task<System.Threading.Tasks.Task>

    2 Work  Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext+<>c.<WaitOnTasks>b__123_1
    4 Work  Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext+<>c.<WaitOnTasks>b__123_0
  266 Work  Microsoft.AspNetCore.SignalR.HubConnectionContext.AbortConnection
 ----
  272

분석 결과, 실제로 스레드 풀 큐에 작업이 적체되어 있었습니다. 일반적으로 이러한 적체는 잠금(lock) 문제로 인해 발생하는 경우가 많습니다. 이를 확인하기 위해 !syncblk 명령어를 실행했습니다.

0:000> !syncblk
Index         SyncBlock MonitorHeld Recursion Owning Thread Info          SyncBlock Owner
-----------------------------
Total           468
CCW             0
RCW             0
ComClassFactory 0
Free            120

잠금과 관련된 문제는 발견되지 않았습니다. 따라서 각 작업 스레드가 왜 느리게 동작하는지 직접 확인해야 했습니다.

2.2 스레드 상태 분석

모든 스레드의 호출 스택을 확인하기 위해 ~*e !clrstack 명령어를 사용했습니다. 출력 결과를 분석한 결과, 많은 스레드가 TryGetConnection 메서드에서 대기 중임을 발견했습니다.

약 143개의 스레드가 TryGetConnection에서 멈춰 있었으며, 이는 데이터베이스 연결을 획득하지 못하고 있음을 의미합니다. 관련 코드를 간소화하면 다음과 같습니다.

private bool TryGetConnection(DbConnection owningObject, uint waitForMultipleObjectsTimeout, bool allowCreate, bool onlyOneCheckConnection, DbConnectionOptions userOptions, out DbConnectionInternal connection)
{
    DbConnectionInternal dbConnectionInternal = null;
    Transaction transaction = null;

    if (HasTransactionAffinity)
    {
        dbConnectionInternal = GetFromTransactedPool(out transaction);
    }
    if (dbConnectionInternal == null)
    {
        Interlocked.Increment(ref _waitCount);
        do
        {
            num = WaitHandle.WaitAny(_waitHandles.GetHandles(allowCreate), (int)waitForMultipleObjectsTimeout);
        } while (dbConnectionInternal == null);
    }
}

private DbConnectionInternal GetFromTransactedPool(out Transaction transaction)
{
    transaction = ADP.GetCurrentTransaction();
    DbConnectionInternal dbConnectionInternal = null;
    if (null != transaction && _transactedConnectionPool != null)
    {
        dbConnectionInternal = _transactedConnectionPool.GetTransactedObject(transaction);
    }
    return dbConnectionInternal;
}

internal DbConnectionInternal GetTransactedObject(Transaction transaction)
{
    lock (_transactedCxns)
    {
        flag = _transactedCxns.TryGetValue(transaction, out value);
    }
    if (flag)
    {
        lock (value)
        {
            int num = value.Count - 1;
            if (0 <= num)
            {
                dbConnectionInternal = value[num];
                value.RemoveAt(num);
            }
        }
    }
    return dbConnectionInternal;
}

코드 분석 결과, _transactedCxns 딕셔너리에서 사용 가능한 연결 객체를 찾지 못해 null을 반환하는 것이 문제였습니다. !dso 명령어를 사용하여 DbConnectionPool 객체의 내부 상태를 확인했습니다.

0:298> !dso
OS Thread Id: 0x42c0 (298)
          SP/REG           Object Name
    0005c087d020     0003ffc79528 Microsoft.Data.ProviderBase.DbConnectionPool

0:298> !do 0003ffc79528
Name:        Microsoft.Data.ProviderBase.DbConnectionPool
...
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
...
000007fe8cd994b0  40001ad       94         System.Int32  1 instance              143 _waitCount
...
000007fe8cd994b0  40001b6       9c         System.Int32  1 instance              100 _totalObjects
...

0:298> !DumpObj /d 00000003ffc7a520
Name:        System.Collections.Generic.Dictionary`2[...]
Fields:
...
000007fe8cd994b0  4002068       38         System.Int32  1 instance                0 _count
...

위 정보에서 세 가지 중요한 사실을 확인할 수 있습니다.

_totalObjects = 100: 연결 풀의 최대 크기는 100입니다.
_count = 0: 현재 모든 100개의 연결이 사용 중입니다.
_waitCount = 143: 143개의 스레드가 연결 획득을 위해 대기 중입니다.

2.3 사용 중인 연결의 위치

연결이 어떤 작업에 사용되고 있는지 확인하기 위해 TDS 전송 계층 메서드인 Microsoft.Data.SqlClient.TdsParserStateObject.TryReadByte를 기준으로 스레드를 검색했습니다. 정확히 100개의 스레드가 이 메서드에서 대기 중이었으며, 대부분의 상위 호출은 GetRoomNosInDltParams 메서드였습니다.

해당 스레드들의 호출 스택을 분석한 결과, 대부분 다음과 유사한 SQL 쿼리를 실행하고 있었습니다.

SELECT [HotelId],
        [RoomId],
        [SubRoomId],
        [SupplierId],
        [RoomNo],
        [RoomCategory],
        [SellPrice],
        [RoomNoState],
        [CheckInDate]
FROM [xxx]
WHERE ((((((([RoomId] IN (673,674)) AND( [SellPrice] > @SellPrice1 ))
        AND ( [CheckInDate] >= @CheckInDate2 ))
        AND ( [CheckInDate] <= @CheckInDate3 ))
        AND ( [RoomCategory] <=@constant5))
        AND ( [RoomNoState] =@constant7))
        AND NOT ([RoomNo] LIKE @MethodConst8+'%') )

역컴파일된 소스 코드를 분석한 결과, useCached 플래그가 제대로 작동하지 않아 매번 데이터베이스에서 데이터를 조회하고 있음을 발견했습니다.

2.4 최적화 제안

SQL에 NOLOCK 힌트 추가: 잠금 경합을 줄이기 위해 적절한 격리 수준을 사용하거나 NOLOCK 힌트를 추가하는 것을 고려합니다.
GetRoomNosInDltParams 메서드 캐싱: 자주 호출되는 쿼리 결과를 메모리 캐시(예: IMemoryCache)에 저장하여 데이터베이스 부하를 줄입니다.
데이터베이스 모니터링: 데이터베이스 측의 잠금, 블로킹, 느린 쿼리를 모니터링하여 병목 지점을 파악합니다.
연결 풀 크기 증가: 연결 풀의 최대 크기(Max Pool Size)를 현재 100에서 더 큰 값(예: 200, 500)으로 늘립니다.

3. 결론

이번 장애는 느린 데이터베이스 쿼리로 인해 ADO.NET 연결 풀(최대 100개)이 고갈되어 발생했습니다. 데이터베이스 모니터링 도구가 있었다면 문제를 더 빨리 발견할 수 있었을 것입니다.

태그: ADO.NET ConnectionPooling ASP.NET Core threadpool Dump Analysis

6월 20일 20:26에 게시됨

괴물 클럽