System.Data.SqlClient.SqlException (0x80131904): Connection Timeout Expired 예외 발생 시 "[Pre-Login] initialization=48; handshake=1944;" 값의 의미
"Connection Timeout Expired" 오류는 보통 Open 메서드 수행 시 발생합니다.
SqlConnection sqlCon = ...;
sqlCon.Open();
예외 메시지는 대략 이렇습니다.
System.Data.SqlClient.SqlException (0x80131904): Connection Timeout Expired. The timeout period elapsed while attempting to consume the pre-login handshake acknowledgement. This could be because the pre-login handshake failed or the server was unable to respond back in time. The duration spent while attempting to connect to this server was - [Pre-Login] initialization=48; handshake=1944; ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
at System.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity identity, SqlConnectionString connectionOptions, SqlCredential credential, Object providerInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString userConnectionOptions, SessionData reconnectSessionData, DbConnectionPool pool, String accessToken, Boolean applyTransientFaultHandling)
at System.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, DbConnectionPoolKey poolKey, Object poolGroupProviderInfo, DbConnectionPool pool, DbConnection owningConnection, DbConnectionOptions userOptions)
at System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(DbConnectionPool pool, DbConnection owningObject, DbConnectionOptions options, DbConnectionPoolKey poolKey, DbConnectionOptions userOptions)
at System.Data.ProviderBase.DbConnectionPool.CreateObject(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
at System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
at System.Data.SqlClient.SqlConnection.Open()
연결 제한 시간이 만료되었습니다. 사전 로그인 핸드세이크 확인을 사용하려는 동안 제한 시간이 경과되었습니다. 이 문제는 사전 로그인 핸드세이크가 실패했거나 서버가 시간 내에 응답할 수 없기 때문일 수 있습니다. 이 서버에 연결하려고 시도할 때 걸린 시간은 [사전 로그인] 초기화=48, 핸드세이크=1944입니다. ---> System.ComponentModel.Win32Exception (0x80004005): 대기 작동이 시작 초과되었습니다.
위의 메시지에서는 대략 2초의 시간 동안 응답이 없어 예외가 발생한 것인데 이런 경우 연결 문자열에 timeout을 2초로 설정했기 때문입니다.
Password=...; User ID=...; Initial Catalog=...; Server=...; CONNECTION TIMEOUT=2;
그런데, 오류 메시지에서 보여주는 시간을 언제나 믿을 수 있는 것은 아닙니다. 가령, 테스트를 위해 가짜 SQL 서버를 다음과 같이 만들어 주고,
using System;
using System.Net;
using System.Net.Sockets;
namespace ConsoleApp1
{
class Program
{
static void Main(string[] args)
{
TcpListener tl = new TcpListener(IPAddress.Any, 2222);
tl.Start(); // 접속 대기만 할 뿐 연결을 Accept하지 않음.
while (true)
{
Console.ReadLine();
}
tl.Stop();
}
}
}
test.aspx 페이지를 만들어 다음과 같은 연결 문자열로 DB 연결을 시도하면,
Password=...; User ID=...; Initial Catalog=...; Server=tcp:localhost,2222; CONNECTION TIMEOUT=2;
"[Pre-Login] initialization=48; handshake=1944;" 같은 시간의 예외 상황을 재현할 수 있습니다. 재미있는 것은, test.aspx를 호출하고 2초 후 (오류 페이지와 함께) 응답이 있었을 때 다시 재빠르게 test.aspx를 호출하면 빠른 응답이 옵니다. 그리고 그때의 오류 메시지에는 여전히 "[Pre-Login] initialization=48; handshake=1944;"처럼 2초의 시간이 걸렸다고 합니다.
제 예상으로는, DB Connection Pool의 영향으로 이전 연결의 재사용으로 인해 initialization/handshake 정보가 초기화되지 않아 이런 문제가 발생하는 듯합니다. 만약 커넥션 풀을 없애면,
Pooling = false;Password=...; User ID=...; Initial Catalog=...; Server=tcp:localhost,2222; CONNECTION TIMEOUT=2;
test.aspx의 두 번째 호출에서조차도 initialization/handshake가 보여주는 정보만큼의 시간이 걸리는 것을 확인할 수 있습니다.
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]