Go gRPC context deadline exceeded 원인 7가지

서론

rpc error: code = DeadlineExceeded desc = context deadline exceeded는 Go gRPC 운영에서 가장 흔하면서도, 원인 스펙트럼이 넓어 디버깅이 어려운 에러입니다. 많은 팀이 “서버가 느린가?” 정도로만 접근하지만, 실제로는 클라이언트 컨텍스트 설정, 이름 해석/연결 수립, LB/Ingress의 idle timeout, 서버의 큐잉/스레드(고루틴) 스케줄링, 다운스트림(DB/외부 API) 지연 등이 복합적으로 얽혀서 발생합니다.

이 글에서는 Go gRPC에서 context deadline exceeded가 발생하는 대표 원인 7가지를 증상 → 확인 방법 → 해결 방향으로 정리합니다. 특히 “어디서 시간이 소모되었는지(연결/요청/서버 처리/응답 전송)”를 분리해 보는 관점에 집중합니다.

> 참고: Kubernetes/EKS 환경에서 503/타임아웃을 함께 겪는다면 인프라 레이어 점검도 병행해야 합니다. 예를 들어 Ingress가 503을 내는데 Pod가 정상인 경우는 EKS Ingress 503인데 Pod 정상일 때 점검 가이드도 같이 보면 원인 분리가 빨라집니다.

1) 클라이언트 deadline을 너무 짧게 줌(또는 전파 중 축소)

대표 증상

로컬에서는 거의 안 나는데, 프로덕션에서 간헐적으로 DeadlineExceeded
서버 로그에는 요청이 도착하지 않거나(연결 단계에서 타임아웃), 도착하더라도 처리 중간에 취소됨

흔한 패턴

상위 요청 컨텍스트(예: HTTP 요청)의 deadline이 짧은데, 그 컨텍스트를 그대로 gRPC 호출에 전달
중간 레이어에서 context.WithTimeout을 여러 번 중첩해 결과적으로 남은 시간이 매우 짧아짐

확인 방법

클라이언트 호출 직전에 남은 시간(deadline - now)을 로깅
gRPC client interceptor로 ctx.Deadline()과 경과 시간을 기록

개선 코드 예시

// 상위 ctx가 너무 짧을 수 있으니, 정책적으로 최소 타임아웃을 보장하거나
// 별도의 RPC용 컨텍스트를 만드는 전략을 사용한다.
func callUserService(parent context.Context, c pb.UserServiceClient, req *pb.GetUserRequest) (*pb.GetUserResponse, error) {
    // 상위 ctx에 deadline이 있더라도, 최소 2초는 보장하고 싶다면 정책을 둔다.
    const minTimeout = 2 * time.Second

    var ctx context.Context
    var cancel func()

    if dl, ok := parent.Deadline(); ok {
        remaining := time.Until(dl)
        if remaining < minTimeout {
            ctx, cancel = context.WithTimeout(context.Background(), minTimeout)
        } else {
            ctx, cancel = context.WithTimeout(parent, remaining)
        }
    } else {
        ctx, cancel = context.WithTimeout(parent, 3*time.Second)
    }
    defer cancel()

    return c.GetUser(ctx, req)
}

> 주의: 무조건 context.Background()로 끊어버리면 취소 전파가 깨져서 리소스 누수/폭주를 부를 수 있습니다. “정책적으로 필요한 최소 보장” 같은 명확한 근거가 있을 때만 사용하세요.

2) DNS/이름 해석 또는 첫 연결(Handshake) 단계에서 타임아웃

대표 증상

첫 호출만 느리거나, 배포 직후/스케일아웃 직후에 타임아웃 증가
서버 애플리케이션 로그에 요청이 아예 안 찍힘

원인 포인트

CoreDNS 지연/불안정
gRPC가 새 커넥션을 만들며 TCP connect + TLS handshake에 시간을 쓰는데 deadline이 짧음
grpc.Dial을 호출해도 실제 연결은 lazy하게 일어날 수 있음(옵션에 따라)

확인 방법

클라이언트에서 grpc.WithBlock()로 dial 단계에서 블로킹시키고, dial 자체가 느린지 분리
GRPC_GO_LOG_SEVERITY_LEVEL=info, GRPC_GO_LOG_VERBOSITY_LEVEL=2 등으로 내부 로그 확인(운영에서는 주의)

개선 코드 예시(연결 단계 분리)

func dialUserService(target string) (*grpc.ClientConn, error) {
    dialCtx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
    defer cancel()

    conn, err := grpc.DialContext(
        dialCtx,
        target,
        grpc.WithTransportCredentials(insecure.NewCredentials()),
        grpc.WithBlock(), // dial 단계에서 timeout을 명확히 적용
    )
    if err != nil {
        return nil, fmt.Errorf("dial failed: %w", err)
    }
    return conn, nil
}

3) 클라이언트 커넥션/스트림 풀 고갈(동시성 과다, backpressure 부재)

대표 증상

트래픽 증가 시점에 비례해 DeadlineExceeded 급증
서버는 CPU/메모리가 여유 있어 보이는데도 클라이언트에서 타임아웃

원인 포인트

단일 ClientConn는 다중 RPC를 멀티플렉싱하지만, 클라이언트 측에서 무제한 고루틴으로 호출하면 로컬 큐잉이 생깁니다.
retry를 무분별하게 걸면 동시성 폭증(“재시도 폭풍”)으로 더 악화

확인 방법

클라이언트 프로세스의 goroutine 수, pprof에서 net/http나 grpc 내부 대기 확인
애플리케이션 레벨에서 동시 호출 수(세마포어) 도입 후 개선되는지 A/B

개선 코드 예시(동시성 제한)

type Limiter struct{ sem chan struct{} }

func NewLimiter(n int) *Limiter { return &Limiter{sem: make(chan struct{}, n)} }
func (l *Limiter) Acquire()     { l.sem <- struct{}{} }
func (l *Limiter) Release()     { <-l.sem }

func callWithLimit(ctx context.Context, lim *Limiter, c pb.UserServiceClient, req *pb.GetUserRequest) (*pb.GetUserResponse, error) {
    lim.Acquire()
    defer lim.Release()

    ctx, cancel := context.WithTimeout(ctx, 800*time.Millisecond)
    defer cancel()

    return c.GetUser(ctx, req)
}

4) 서버에서 요청은 도착하지만 “큐에서 기다리다” deadline 초과 (스레드/고루틴/리소스 포화)

대표 증상

서버 access log에는 요청이 찍히지만 처리 완료 로그가 없음
서버 CPU가 100%가 아니어도, 특정 락/채널/풀에서 대기하며 지연

원인 포인트

DB 커넥션 풀 고갈, 외부 API 동시성 제한, 글로벌 락 경합
gRPC handler 내부에서 블로킹 작업을 수행(동기 I/O, 큰 파일 읽기 등)

확인 방법

서버에 unary interceptor로 “handler 진입~종료 시간”과 ctx.Err() 기록
pprof로 block profile / mutex profile / goroutine dump 확인

서버 측 인터셉터 예시(지연/취소 관찰)

func timingUnaryServerInterceptor(
    ctx context.Context,
    req any,
    info *grpc.UnaryServerInfo,
    handler grpc.UnaryHandler,
) (any, error) {
    start := time.Now()
    resp, err := handler(ctx, req)
    dur := time.Since(start)

    // ctx.Err()가 context deadline exceeded인지 확인
    if errors.Is(ctx.Err(), context.DeadlineExceeded) {
        log.Printf("DEADLINE: method=%s dur=%s err=%v", info.FullMethod, dur, err)
    } else {
        log.Printf("OK/ERR: method=%s dur=%s err=%v", info.FullMethod, dur, err)
    }
    return resp, err
}

5) 다운스트림(특히 DB) 지연: 쿼리 슬로우/락/Autovacuum bloat

대표 증상

특정 API만 유독 DeadlineExceeded
서버 p95/p99가 DB 지연과 강하게 상관

원인 포인트

슬로우 쿼리, 인덱스 미스, 테이블 bloat로 인한 디스크 I/O 증가
트랜잭션 락 경합으로 대기

확인 방법

gRPC handler 내부에서 DB 호출 시간을 분리 로깅
Postgres라면 pg_stat_statements, auto_explain, slow query log

개선 방향

쿼리/인덱스 튜닝, 커넥션 풀 사이즈 재조정, 락 경합 완화
bloat가 의심되면 VACUUM/AUTOVACUUM 튜닝도 같이 봐야 합니다: PostgreSQL VACUUM·AUTOVACUUM 튜닝 - bloat로 느려질 때

DB 호출에 별도 deadline을 주는 예시

func (s *Server) GetUser(ctx context.Context, req *pb.GetUserRequest) (*pb.GetUserResponse, error) {
    // 전체 RPC deadline과 별개로 DB에 더 짧은 타임아웃을 둬서
    // "DB에서 다 써버려서" 응답을 못하는 상황을 줄인다.
    dbCtx, cancel := context.WithTimeout(ctx, 150*time.Millisecond)
    defer cancel()

    u, err := s.repo.FindUser(dbCtx, req.Id)
    if err != nil {
        return nil, status.Errorf(codes.Internal, "db error: %v", err)
    }
    return &pb.GetUserResponse{Id: u.ID, Name: u.Name}, nil
}

6) LB/Ingress/프록시의 timeout·idle timeout·최대 요청 시간 제한

대표 증상

서버/클라이언트 모두 “타임아웃 설정은 충분한데” 중간에서 끊김
긴 스트리밍/대용량 응답에서 특히 잘 발생
gRPC status는 DeadlineExceeded로 보이지만, 실제로는 네트워크 중간에서 연결이 끊겨 재시도/대기하다가 deadline을 넘김

원인 포인트

ALB/NLB/Envoy/NGINX Ingress의 idle timeout
HTTP/2 keepalive 정책 불일치(중간 장비가 ping을 이상 트래픽으로 보고 끊음)

확인 방법

Ingress/LB 액세스 로그에서 upstream timeout/connection termination 확인
같은 RPC를 Pod IP로 직접 호출해(프록시 우회) 재현 여부 비교

개선 방향

Ingress/LB의 gRPC 관련 timeout 설정을 서비스 특성에 맞게 조정
keepalive 파라미터를 클라이언트/서버/프록시가 모두 수용 가능한 값으로 맞춤

> EKS에서 “Pod는 정상인데 503/타임아웃”류는 인그레스/엔드포인트/리드니스가 엮이는 경우가 많습니다. 환경이 EKS라면 EKS에서 Pod는 Running인데 503가 뜰 때 점검도 함께 점검하세요.

7) 타임아웃/취소 처리 오류: 컨텍스트를 무시하거나, 취소 후 작업 지속

대표 증상

클라이언트는 DeadlineExceeded인데 서버는 계속 작업을 수행(비싼 작업이 계속 돌아감)
재시도와 결합하면 서버가 더 느려지고 타임아웃이 폭증

원인 포인트

handler 내부에서 ctx.Done()을 체크하지 않음
고루틴을 띄워놓고 컨텍스트 취소 시 정리(cleanup)하지 않음
스트리밍에서 Send/Recv 에러를 무시하고 루프 지속

확인 방법

서버에서 ctx.Err()를 주기적으로 확인
스트리밍 루프에서 Send/Recv 반환 에러를 즉시 처리

개선 코드 예시(취소에 반응하는 작업)

func doExpensiveWork(ctx context.Context) error {
    ticker := time.NewTicker(50 * time.Millisecond)
    defer ticker.Stop()

    for i := 0; i < 200; i++ { // 예: 10초짜리 작업
        select {
        case <-ctx.Done():
            return ctx.Err() // deadline exceeded / canceled
        case <-ticker.C:
            // 작은 단위로 작업을 쪼개 진행
        }
    }
    return nil
}

func (s *Server) Heavy(ctx context.Context, req *pb.HeavyRequest) (*pb.HeavyResponse, error) {
    if err := doExpensiveWork(ctx); err != nil {
        // ctx.Err()를 gRPC status로 매핑
        if errors.Is(err, context.DeadlineExceeded) {
            return nil, status.Error(codes.DeadlineExceeded, "deadline")
        }
        if errors.Is(err, context.Canceled) {
            return nil, status.Error(codes.Canceled, "canceled")
        }
        return nil, status.Errorf(codes.Internal, "work failed: %v", err)
    }
    return &pb.HeavyResponse{Ok: true}, nil
}

빠른 진단 체크리스트(현장용)

1) “서버에 요청이 도착했는가?”부터 분리

서버 로그/메트릭에 해당 RPC가 찍히는지 확인
안 찍히면: DNS/연결/Ingress/LB 쪽 원인(2, 6)을 우선

2) “도착했는데 처리 시간이 긴가, 큐에서 대기했나?”

서버 인터셉터로 handler 실행 시간 측정(4)
DB/외부 API 호출 시간을 분리 로깅(5)

3) “클라이언트가 스스로 병목을 만들었나?”

동시 호출 수, goroutine 수, 재시도 정책 확인(3)
deadline이 상위 컨텍스트에서 과도하게 짧게 내려오는지 확인(1)

결론

Go gRPC의 context deadline exceeded는 단순히 “타임아웃 늘리면 된다”로 끝나지 않습니다. (1) 컨텍스트 정책, (2) 연결/DNS, (3) 동시성/재시도, (4) 서버 큐잉, (5) DB/다운스트림, (6) Ingress/LB timeout, (7) 취소 처리까지 7가지 축으로 원인을 분해하면, 재현이 어려운 간헐 장애도 훨씬 빠르게 수습할 수 있습니다.

운영 환경에서 가장 효율적인 접근은 “deadline을 늘리기”가 아니라, 어느 구간에서 시간이 소비되는지 관측 가능하게 만들고(interceptor/metrics), 병목 구간을 분리해 제거하는 것입니다.