EF Core 사용시 첫 번째 쿼리가 느린 문제

안녕하세요.

현재 ASP.NET CORE(.net 8)를 통해서 REST API를 만들어 보는 연습을 하고 있습니다. 그리고 DB는 Docker로 PostgreSQL을 띄웠고, EF Core(ver. 8.0.7)를 통해 DB에 접근하고 있습니다.

그런데 연습 과정에서 두 가지 문제를 발견했습니다.

문제 1)

서버 실행 후 첫 번째로 실행되는 쿼리가 매우 느립니다. 하지만 그 다음 두 번째 쿼리부터는 정상적인(빠른) 속도를 보여줍니다.

[첫 번째 쿼리 실행 - 응답까지 약 8.8s]

[두 번째 쿼리 실행 - 응답까지 약 11ms]

개발을 하다보면 서버를 내렸다 올렸다 반복하게 되는데, 이럴때마다 첫 번째 쿼리는 8초정도 기다린 후 응답을 받으니 꽤나 답답했습니다.

문제 2)

첫 번째 쿼리 수행 후 다음 쿼리부터는 정상적인 속도를 보여줬으나, (서버를 내리지 않고 가만히 있다가) 5분 후에 다시 쿼리를 보내보면 또다시 8초를 기다린 후에 응답을 받을 수 있었습니다.

DB도 확인해보면서 몇 번 테스트를 해보니, ASP.NET Core와 연결된 (IDLE 상태의) 커넥션이 5분 후에 사라지는 것을 보았습니다.


(위 그림에선 pid 6157이 5분후에 사라짐)

커넥션이 사라진 후 쿼리를 날릴 때마다 느린 응답 속도를 보여줬습니다.

NPGSQL(ADO.NET Data Provider for PostgreSQL) 공식문서를 확인해보니 Pooling 관련 Default 옵션이 다음과 같았습니다. (참고: Connection String Parameters | Npgsql Documentation)

  • Minimum Pool Size : 0
  • Connection Idle Lifetime : 300

즉, 최소로 유지하고자 하는 Connection이 0개이므로 Idle 상태의 Connection은 5분 후면 자동으로 제거되고, 이후의 쿼리는 새로운 Connection을 생성하게 되면서 느린 응답 속도를 보여줬던게 아닌가 싶습니다.

저는 위와 같은 두 가지 문제를 발견하고 다음과 같이 조치를 취해봤습니다.

문제 2에 대한 조치)

// Program.cs

builder.Services.AddDbContext<ApplicationDbContext>(
    options => options.UseNpgsql(builder.Configuration.GetConnectionString("ShirtStoreManagement"))
);  
{
  "ConnectionStrings": {
    "ShirtStoreManagement": "Host=localhost;Port=5432;Database=ShirtStoreManagement;Username=postgres;Password=postgres;Include Error Detail=true;Minimum Pool Size=5;Keepalive=30"
  },
         :
         :
}

위와 같이 Connection Pool의 최소 사이즈를 5로 설정하고, KeepAlive 옵션을 통해 Idel 상태의 Connection을 계속 유지할 수 있도록 했습니다.

이처럼 설정을 하니 5분, 10분이 지난 후에 쿼리를 다시 날려도, 가지고 있는 connection을 바로 사용하기 때문에 빠른 응답 속도를 받아 볼 수 있었습니다.

또한 다른 방법으로는, 위처럼 Connection String에 추가적인 옵션을 추가하지 않고, AddDbContextPool을 사용하는 것만으로도 두 번째 문제는 해결이 될 수 있었습니다.

builder.Services.AddDbContextPool<ApplicationDbContext>(
    options => options.UseNpgsql(builder.Configuration.GetConnectionString("ShirtStoreManagement"))
);  

문제 1에 대한 조치)

첫 번째 문제는 서버가 실행될 때 생성된 Connection이 없기 때문에 첫 번째 쿼리가 느린 것이라고 판단을 해서, 다음과 같은 생각으로 조치를 취해봤습니다.

“서버가 실행되는 과정에서 미리 쿼리를 날려 Connection을 생성해보자”

// Program.cs

using Microsoft.EntityFrameworkCore;
using WebAPIDemo.Data;
using WebAPIDemo.MyCompiledModels;

var builder = WebApplication.CreateBuilder(args);

// Add services to the container.
// Learn more about configuring Swagger/OpenAPI at https://aka.ms/aspnetcore/swashbuckle
builder.Services.AddEndpointsApiExplorer();
builder.Services.AddSwaggerGen();

builder.Services.AddDbContextPool<ApplicationDbContext>(
    options => options.UseNpgsql(builder.Configuration.GetConnectionString("ShirtStoreManagement"))
);

builder.Services.AddControllers();

var app = builder.Build();

using (var scope = app.Services.CreateScope())
{
    var dbContext = scope.ServiceProvider.GetRequiredService<ApplicationDbContext>();
    try
    {
        // Execute "SELECT 1;" to initialize the database connection
        dbContext.Database.ExecuteSqlRaw("SELECT 1;");
        Console.WriteLine("Database connection initialized successfully.");
    }
    catch (Exception ex)
    {
        Console.WriteLine($"Error during database initialization: {ex.Message}");
        throw;
    }
}

// Configure the HTTP request pipeline.
if (app.Environment.IsDevelopment())
{
    app.UseSwagger();
    app.UseSwaggerUI();
}

app.UseHttpsRedirection();
app.MapControllers();

app.Run();

Program.cs 중간에 있는 using 구문에서 “SELECT 1;” 쿼리를 날려 DB와의 Connection을 미리 생성하도록 해봤습니다.

비록 서버가 실행되는데 걸리는 시간이 약간 더 추가됐지만, 서버가 열린 후 첫 번째 DB 쿼리 수행에서 빠른 응답 속도(ms 단위)를 얻을 수 있었습니다.

기본적인 CRUD 기능의 API를 구현해보면서 발견한 문제를 나름대로 해결해봤으나, 무언가 석연치 않은 느낌입니다… 원인을 잘못 파악한 것은 아닌지, asp.net core와 ef core를 잘못 사용한건 아닌지… 더 좋은 방법이 있을 것만 같은 느낌입니다… ㅠㅜ

위와 같은 문제를 겪어보신 분이나, 더 올바른 방법을 알고 계신분이 있다면 조언 부탁드리겠습니다…!

3 Likes

첫 쿼리가 후속 쿼리보다 느린 건 맞지만, 8초는 느려도 너무 느린 것 같습니다.

ado.net, psql 로도 동일 증상인가요?

2 Likes

말씀해주신 조건으로는 테스트 해보지 않았습니다!

프로바이더나 데이터베이스를 바꿔가면서
동일한 증상이 있는지도 확인해봐야겠네요:astonished:

5건 조회하는데 8초인가요? 너무 느린데요…
도커쪽 문제 아닌가 싶습니다.
아무리 EF라 해도 8초는 너무 심하네요.
보통 0.00 몇초 일텐데

1 Like

네에 ㅠㅜㅎㅎ 고작 몇개 없는 데이터 조회하는건데,
8초나 기다린 후에 응답을 받습니다.

# docker-compose.yml

services:
  postgres:
    image: postgres:latest
    container_name: postgres
    ports:
        - 5432:5432
    volumes:
        - ./Containers/Postgres:/var/lib/postgresql/data
    environment:
        - POSTGRES_USER=postgres
        - POSTGRES_PASSWORD=postgres
        - POSTGRES_DB=ShirtStoreManagement

Docker(postgresql)는 별다른 추가 설정 없이 사용중입니다

컨테이너와의 통신에 문제 원인이 있는걸까요?:thinking:
이와 관련해서도 한 번 알아볼 필요가 있겠네요!

원래 저는 DB와의 초기 connection 생성이 오래 걸리는건가 싶었는데,
EF Core first query slow, EF Core cold start 등과 같은 키워드로 검색을 해보면 비슷한 증상에 대한 질문들이 꽤 있더라구요.

답변들을 보면 EF Core는 첫 쿼리를 실행할 때 DB Contex 모델을 초기화하는 등 웜업이 필요해서 첫 번째 쿼리가 느린 건 자연스러운 일이라고 하네요.
(c# - Entity Framework Core is slow when executing the first query - Stack Overflow)
(Slow First Query after project startup · Issue #27392 · dotnet/efcore · GitHub)

근데 아무리 그래도 8초나 걸려서 응답을 받는건 또다른 문제가 있는게 아닐까 싶습니다:sob:

@HyunJi_Lee 님의 말씀에 힌트를 얻어서, 다시 한 번 테스트를 해봤습니다.

Web API 서버가 Docker로 띄워진 DB 컨테이너를 찾는데 시간이 오래 걸리는게 아닌가?

{
  "ConnectionStrings": {
    "ShirtStoreManagement": "Host=localhost;Port=5432;Database=ShirtStoreManagement;Username=postgres;Password=postgres;Include Error Detail=true;"
  },
     :
     :
}

만약 ASP.NET Core 애플리케이션도 Docker Container로 띄웠다면, Connection String에서 HostDB 컨테이너의 이름을 사용했을 것입니다.

하지만 저는 DB(PostgreSQL)만 컨테이너로 띄웠었기 때문에, Hostlocalhost로 설정했었습니다.

그래서 이번에는 localhost 대신 127.0.0.1로 수정 후 다시 한 번 테스트를 해봤습니다.

{
  "ConnectionStrings": {
    "ShirtStoreManagement": "Host=127.0.0.1;Port=5432;Database=ShirtStoreManagement;Username=postgres;Password=postgres;Include Error Detail=true;"
  },
     :
     :
}

그랬더니 첫 쿼리 응답 속도가 8초 걸리던게, 1초대로 줄어들었습니다!

아무래도 호스트 네트워크와 Dokcer 네트워크 간의 DNS 과정이 가장 큰 문제 원인이었던 거 같습니다:face_holding_back_tears:

Connection String의 Host를 localhost에서 127.0.0.1로 변경함으로써, 본문에서 언급했던 문제 1)문제 2)가 모두 해결됐네요!

  • 문제 1) 서버 실행 후 첫 번째 쿼리의 응답 속도가 8초였던 문제
    • 이제는 DB를 빠르게 찾아 Connection을 맺기 때문에 8초에서 1초로 단축
    • 사실상 Connection을 맺고 쿼리 응답받는건 오래 걸리지 않음
      (앱 실행 후 최초 쿼리는 DB Context의 모델 초기화로 인해 좀 더 지연되는 부분이 있는걸로 추측)
  • 문제 2) Connection 유실 후 쿼리 수행하면 다시 8초대 응답을 받던 문제
    • 마찬가지로 DB를 빠르게 찾아 Connection을 맺기 때문에 문제 해결
    • 새로운 Connection을 맺고 쿼리 응답을 받는데 수십 또는 100ms 정도 걸림

제가 처음에 조치를 취해던 방법은 “Connection을 맺는 시간이 오래 걸리니까, API 서버 초기 실행 때 DB Connection을 미리 만들어 놓고 계속 유지하자” 였는데,

알고보니 Connection을 맺기 위해 DB를 찾는 시간이 오래 걸린거였고, 결국엔 불필요한 DNS 과정을 생략함으로써 모든 문제가 한 번에 해결됐습니다 ㅎㅎ

앞으로는 다음 사항에 유의하며 개발 공부를 해야겠습니다:sweat_drops:

  • 같은 Docker 네트워크로 묶여 있는 Docker 컨테이너들이라면 서로 컨테이너 이름을 이용하여 통신한다.
  • 호스트 네트워크에 있는 애플리케이션과 (포트포워딩된) Docker 컨테이너를 연결할 때는 localhost 대신 127.0.0.1를 사용함으로써 불필요한 DNS 과정이 생략되어 더 빠르게 통신한다.
10 Likes

localhost 는 127.0.0.1 의 별칭에 지나지 않다고 알고 있습니다. 즉, 둘의 차이가 없어야 정상이죠.
뭔가 다른 이유가 있을 듯 합니다.

3 Likes

넵! 말씀해주신 것 처럼 localhost127.0.0.1의 별칭, 즉 사람이 이해하기 쉬운 도메인 이름입니다.

그래서 저도 이 둘의 차이가 네트워킹 속도에 영향을 미치는 것이 의아했습니다.:thinking:

테스트 결과에서는 확실히 127.0.0.1로 접근해야 더 빠른 속도를 보여줬기 때문에
내부적으로 DNS 해석 과정에서 어떠한 차이가 있었나보구나 하고 넘겨짚고 넘어갔습니다.:sweat_drops:

하지만 추후에 다음과 같은 주제로 한 번 공부해봐야겠다는 생각은 들더군요!

  • 로컬 네트워크에서 이뤄지는 DNS 과정이 어떻게 이뤄지는가
  • 이를 추적해보고 눈으로 확인해볼 수 있는 방법이 있는가

어쨌든 @BigSquare 님의 답변을 보고 문득 의심되는 부분이 떠올랐습니다!

추측 1) WSL2의 Mirrored mode 설정

과거에 wsl2에서 개발하면서, 외부 접속에 대한 편의성을 위하여 WSL2 Mirrored 모드를 설정했던 기억이 떠올랐습니다.

# .wslconfig

[wsl2]
networkingMode=mirrored

추측 2) host 파일(feat. Docker)

ip 주소와 도메인을 매핑 해주는 host 파일을 열어보니 다음과 같이 설정되어 있었습니다.

# hosts

# For example:
#
#      102.54.94.97     rhino.acme.com          # source server
#       38.25.63.10     x.acme.com              # x client host
# localhost name resolution is handled within DNS itself.
#	127.0.0.1       localhost
#	::1             localhost

# Added by Docker Desktop
192.168.45.93 host.docker.internal
192.168.45.93 gateway.docker.internal
# To allow the same kube context to work on the host and the container:
127.0.0.1 kubernetes.docker.internal
# End of section

아마도 위 내용들로 인해 Windows의 네트워크 인터페이스나 도메인(localhost) 해석 과정에 영향을 미친 것이 아닌가 싶습니다…! :face_with_raised_eyebrow:

7 Likes

질문과 관련 전개가 매력적입니다. 다른 분들께 도움이 될 것이라 생각합니다. 앞으로의 활동이 기대됩니다!

2 Likes

웹이나 서비스 개발 같은 쪽에선 의외로 자주 보이는 이슈이죠ㅎ

3 Likes

이게 원인이지 않을까요?

호스트 파일은 웬만하면 안 건드는데, 도커가 건드는 바람에, localhost 도메인 네임을 찾기 위해 외부 DNS로 한 바뀌 돌고 온 건 아닌지 하는 생각을 해봅니다.

제피셜 상, 주석을 해제하면, DB 커넥션에 한 해, 둘의 차이가 없을 것 같습니다.
주석을 해제함으로써, 발생하는 도커 설정에 문제가 발생할지도 모르지만요.

3 Likes

좋은 말씀 감사드립니다!

혼자서 끙끙 앓던 문제였는데,
확실히 질문을 통해 다른 사람들의 의견을 접함으로써 문제를 다각도로 바라볼 수 있었고 차근차근 원인을 찾아가는 재미가 있었던 거 같습니다 :smile:

1 Like

네엡:joy: 앞으로 비슷한 이슈들을 맞딱뜨리면, 이번 경험을 토대로 잘 헤쳐나가보겠습니다 ㅎㅎ

1 Like

넵 말씀해주신대로 host 파일의 해당 내용을 주석 해제하고 테스트 해봤지만,
제가 겪었던 문제는 해결되지 않았습니다:rofl:
(wsl2 mirrored mode도 영향을 미친게 아닐까 싶은…)

그래서 일단은 저도 Docker 설정에 문제가 생길까봐 다시 원상 복구하고ㅎㅎ
DB connection string에는 localhost 대신 127.0.0.1을 사용하도록 했습니다.

문제를 해결해나가는데 계속 관심을 갖고 의견을 주셔서 감사합니다!

2 Likes

이렇게 잘 정리된 문제 상황과 그 해결 과정에 동참하는 것 자체가 즐거움입니다.

저도 많이 배웠고, 다른 분들에게도 많이 도움이 되었을 것으로 생각합니다.

3 Likes