[Go] 서버 개발자를 위한 graceful shutdown 가이드

[요약]

• graceful shutdown을 적용하면 클라이언트가 타임아웃으로 인해 실패한 요청을 다른 서버로 재시도를 못하는 케이스를 막을 수 있습니다.
• gRPC와 echo 프레임워크 모두 graceful shutdown 함수를 지원하여 쉽게 구현할 수 있습니다.

graceful shutdown 적용 필요성

서버가 요청을 처리하다 갑자기 종료되면 처리가 거의 완료된 요청들도 정상 응답을 반환하지 못하고 에러를 반환합니다. 클라이언트는 에러가 발생한 요청을 마저 처리하기 위해 이중화된 다른 서버로 보낼 테지만 타임아웃 내 요청을 완료하기 충분하지 않을 수 있습니다.

graceful shutdown을 하면 서버가 새로운 요청은 받지 않고 처리 중인 요청들을 전부 완료하고 종료합니다. 그래서 클라이언트는 서버가 종료 중이더라도 정상 응답을 받거나 즉시 에러를 받습니다. 에러를 반환 받더라도 다른 서버로 요청을 보낼 수 있는 시간이 비교적 충분해 타임 아웃이 발생할 확률이 적어집니다.

너무 오래 걸리는 요청이 존재시 graceful shutdown이 오래 걸릴 수 있으므로 일정 시간이 지나면 강제 종료하는 로직을 추가하면 좋습니다.

GOAWAY

HTTP2 명세에는 GOAWAY가 정의되어 있습니다. GOAWAY는 커넥션을 끝내고 싶을 때 보내는 프레임으로, greaceful shutdown시 활용할 수 있습니다.

GOAWAY 프레임은 last stream id를 가지고 있습니다. last stream id는 GOAWAY 프레임을 보낸 서버가 자신이 받고 처리한 프레임 id 중 가장 큰 값입니다.

GOAWAY 프레임을 받은 클라이언트는 last stream id를 보고 해당 id 이하인 프레임은 전부 처리가 되었고, 이후에 보낸 프레임은 처리가 되지 않음을 확인할 수 있습니다.

구체적으로 graceful shutdown에서 GOAWAY가 처리되는 방식은 다음과 같습니다.

1. 서버가 graceful shutdown을 시작할 때 GOAWAY를 보냅니다. 이때 last stream id는 최댓값(2^31-1)입니다.
2. 클라이언트는 첫번째 GOAWAY를 받고 서버가 커넥션을 곧 끝낼 것이라는 것을 인지합니다. 더 이상 추가 요청을 보내지 않습니다.
3. 1과 2 사이 클라이언트가 보낸 요청들은 서버가 처리할 책임이 있습니다. 서버는 round trip time을 기다리고 자신이 받은 프레임 중 가장 최신 id를 기록하여 두번째 GOAWAY를 보냅니다(참고로 go gRPC의 경우 첫번째 GOAWAY를 보낸 직후 Ping을 보내고 Ping 응답이 돌아올 때까지 들어온 요청까지 처리합니다)
4. 서버는 두번째 GOAWAY에 적힌 id보다 높은 프레임이 들어오면 버립니다(커넥션 상태를 변경하는 일부 프레임 제외).

HTTP2를 사용하는 서버들은 graceful shutdown을 할 때 반드시 GOAWAY를 보내야 한다고 명시되어 있습니다.

예를 들어 gRPC는 HTTP2를 기반으로 한 프로토콜이기 때문에 gRPC 구현체들의 graceful shutdown 함수를 살펴보면 GOAWAY를 보내는 것을 확인할 수 있습니다.

gRPC 서버 강제 shutdown시 클라이언트가 받는 응답

graceful shutdown을 하지 않고 종료했을 때 어떤 결과가 발생하는지 알아보겠습니다.

테스트 코드는 다음과 같습니다. (다음 코드를 변경했습니다: https://github.com/grpc/grpc-go/tree/master/examples/features/keepalive)

서버

package main

import (
	...
)

var port = flag.Int("port", 50052, "port number")

// server implements EchoServer.
type server struct {
	pb.UnimplementedEchoServer
}

func (s *server) UnaryEcho(_ context.Context, req *pb.EchoRequest) (*pb.EchoResponse, error) {
	time.Sleep(1 * time.Second)
	return &pb.EchoResponse{Message: req.Message}, nil
}

func main() {
	flag.Parse()

	address := fmt.Sprintf(":%v", *port)
	lis, err := net.Listen("tcp", address)
	if err != nil {
		log.Fatalf("failed to listen: %v", err)
	}

	s := grpc.NewServer()
	pb.RegisterEchoServer(s, &server{})

	if err := s.Serve(lis); err != nil {
		log.Fatalf("failed to serve: %v", err)
	}
}

클라이언트

package main

import (
	...
)

var addr = flag.String("addr", "localhost:50052", "the address to connect to")
var vuser = 300

func main() {
	flag.Parse()

	conn, err := grpc.NewClient(*addr, grpc.WithTransportCredentials(insecure.NewCredentials()))
	if err != nil {
		log.Fatalf("did not connect: %v", err)
	}
	defer conn.Close()

	c := pb.NewEchoClient(conn)

	ctx, cancel := context.WithTimeout(context.Background(), 3*time.Minute)
	defer cancel()

	wg := sync.WaitGroup{}
	for i := 0; i < vuser; i++ {
		go func() {
			wg.Add(1)
			defer wg.Done()
			for {
				start := time.Now()
				_, err := c.UnaryEcho(ctx, &pb.EchoRequest{Message: "keepalive demo"})
				duration := time.Since(start)
				if err != nil {
					fmt.Println(duration, " unexpected error from UnaryEcho: ", err, conn.GetState())
					break
				}
			}
		}()
	}
	wg.Wait()

	fmt.Println("done", conn.GetState())
}

GODEBUG=http2debug=2 환경 변수를 설정하고 클라이언트 코드를 실행하였습니다.

이때 서버가 갑자기 종료되면, 클라이언트가 받은 응답은 다음과 같습니다.

2024/11/19 18:12:45 http2: Framer 0x140004d6000: read WINDOW_UPDATE len=4 (conn) incr=21
2024/11/19 18:12:45 http2: Framer 0x140004d6000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2024/11/19 18:12:45 http2: Framer 0x140004d6000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2024/11/19 18:12:45 http2: Framer 0x140004d6000: wrote GOAWAY len=33 LastStreamID=8999 ErrCode=NO_ERROR Debug="client transport shutdown"
298.066917ms  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = error reading from server: EOF READY
459.873125ms  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = error reading from server: EOF IDLE
395.322875ms  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = error reading from server: EOF IDLE
...

PING의 응답을 받지 못하자 커넥션이 종료된 것을 감지하고 클라이언트에서 GOAWAY를 보내는 것을 확인할 수 있었습니다. 이후 클라이언트는 에러로 EOF를 반환합니다.

위 실험은 vuser가 300일 때로 서버의 부하가 그리 크지 않았습니다.

vuser를 5000으로 변경하여 같은 실험을 하면 응답이 조금 달라집니다.

2024/11/19 18:19:12 http2: decoded hpack field header field ":status" = "200"
2024/11/19 18:19:12 http2: decoded hpack field header field "content-type" = "application/grpc"
2024/11/19 18:19:12 http2: Framer 0x140019640e0: read DATA stream=13811 len=21 data="\x00\x00\x00\x00\x10\n\x0ekeepalive demo"
2024/11/19 18:19:12 http2: Framer 0x140019640e0: read HEADERS flags=END_STREAM|END_HEADERS stream=13811 len=2
2024/11/19 18:19:12 http2: decoded hpack field header field "grpc-status" = "0"
2024/11/19 18:19:12 http2: decoded hpack field header field "grpc-message" = ""
866.050209ms  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = error reading from server: read tcp [::1]:60671->[::1]:50052: read: connection reset by peer IDLE
35.86725ms  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = error reading from server: read tcp [::1]:60671->[::1]:50052: read: connection reset by peer IDLE
957.132667ms  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = error reading from server: read tcp [::1]:60671->[::1]:50052: read: connection reset by peer CONNECTING
906.545166ms  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = error reading from server: read tcp [::1]:60671->[::1]:50052: read: connection reset by peer IDLE
866.10175ms  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = error reading from server: read tcp [::1]:60671->[::1]:50052: read: connection reset by peer IDLE

PING과 GOAWAY를 주고 받는 과정이 없이 바로 에러가 발생합니다.

또한 에러가 EOF가 아닌 connection reset by peer로 변경되었습니다.

connection reset by peer는 TCP 통신에서 서버가 RST 패킷으로 응답했을 때 발생하는 에러입니다. RST 패킷을 응답으로 받는 경우는 서버가 해당 패킷을 받는 커넥션이 존재하지 않을 때 발생합니다. 즉 클라이언트가 커넥션이 종료된 것을 감지하지 못하고 패킷을 보냈다고 추측할 수 있습니다.

gRPC 서버 graceful shutdown시 클라이언트가 받는 응답

서버에 graceful shutdown 함수를 적용하면 다음과 같습니다.

package main

import (
	...
)

var port = flag.Int("port", 50052, "port number")

// server implements EchoServer.
type server struct {
	pb.UnimplementedEchoServer
}

func (s *server) UnaryEcho(_ context.Context, req *pb.EchoRequest) (*pb.EchoResponse, error) {
	time.Sleep(1 * time.Second)
	return &pb.EchoResponse{Message: req.Message}, nil
}

func main() {
	flag.Parse()

	address := fmt.Sprintf(":%v", *port)
	lis, err := net.Listen("tcp", address)
	if err != nil {
		log.Fatalf("failed to listen: %v", err)
	}

	s := grpc.NewServer()
	pb.RegisterEchoServer(s, &server{})

	go func() {
		if err := s.Serve(lis); err != nil {
			log.Fatalf("failed to serve: %v", err)
		}
	}()

	ch := make(chan os.Signal)

	signal.Notify(ch, syscall.SIGINT, syscall.SIGTERM)
	sig := <-ch
	log.Printf("received signal: %v", sig)
	s.GracefulStop()
}

RST가 발생했던 vuser 5000 클라이언트 코드로 요청을 보내고, 서버를 shutdown 시켰을 때 받은 응답을 살펴보았습니다.

2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read GOAWAY len=21 LastStreamID=2147483647 ErrCode=NO_ERROR Debug="graceful_stop"
2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read PING len=8 ping="\x01\x06\x01\b\x00\x03\x03\t"
2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read DATA stream=8793 len=21 data="\x00\x00\x00\x00\x10\n\x0ekeepalive demo"
2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read HEADERS flags=END_STREAM|END_HEADERS stream=8793 len=2

...

274.75µs  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp [::1]:50052: connect: connection refused" TRANSIENT_FAILURE
154.75µs  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp [::1]:50052: connect: connection refused" TRANSIENT_FAILURE
97.417µs  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp [::1]:50052: connect: connection refused" TRANSIENT_FAILURE

...

2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read WINDOW_UPDATE len=4 (conn) incr=25893
2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read WINDOW_UPDATE len=4 (conn) incr=9324
2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2024/11/19 18:45:11 http2: Framer 0x14001e7a000: read GOAWAY len=21 LastStreamID=18697 ErrCode=NO_ERROR Debug="graceful_stop"

...

13.416µs  unexpected error from UnaryEcho:  rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp [::1]:50052: connect: connection refused" TRANSIENT_FAILURE

HTTP2 명세에 나온 것처럼 클라이언트는 총 두 번의 GOAWAY를 받는 것을 확인할 수 있습니다.

또한 에러 응답 시간이 ms → µs 단위로 크게 떨어진 것을 확인할 수 있습니다.

에러 응답 시간이 크게 줄어들었기 때문에 실패한 요청을 다른 서버로 요청할 시간이 충분하고 타임 아웃이 발생하는 경우를 크게 낮출 수 있습니다.

go의 http 라이브러리 shutdown 함수

http 라이브러리 Shutdown 함수는 http2를 가정하지 않기 때문에 GOAWAY 프레임을 쓰지 않습니다.

Shutdown 함수의 로직은 다음과 같습니다.

• 요청을 처리 중인 커넥션은 닫지 않습니다.
• 열려있는 listener들, idle connection을 차례로 닫고 처리 중인 커넥션이 idle이 될 때까지 기다린 후 shutdown합니다.

이때 처리 중인 커넥션을 기다리는 간격은 지수적으로 증가합니다.

pollIntervalBase := time.Millisecond
	nextPollInterval := func() time.Duration {
		// Add 10% jitter.
		interval := pollIntervalBase + time.Duration(rand.Intn(int(pollIntervalBase/10)))
		// Double and clamp for next time.
		pollIntervalBase *= 2
		if pollIntervalBase > shutdownPollIntervalMax {
			pollIntervalBase = shutdownPollIntervalMax
		}
		return interval
	} 
	
	timer := time.NewTimer(nextPollInterval())
	defer timer.Stop()
	for {
		if srv.closeIdleConns() {
			return lnerr
		}
		select {
		case <-ctx.Done():
			return ctx.Err()
		case <-timer.C:
			timer.Reset(nextPollInterval())
		}
	}

아쉽게도 최대 간격 시간은 500 ms로 고정되어 조절할 수 없습니다. 대신 go의 context를 이용해서 graceful shutdown의 타임 아웃을 설정할 수 있습니다.

위와 같은 서버 조건(정상 응답 1초)에서 shutdown시 에러를 응답받는 시간을 비교하였습니다.

다만 gRPC에 비해 많은 요청을 수행하지 못하여 vuser가 100일 때로 실험하였습니다.

클라이언트 코드

package main

import (
	"flag"
	"fmt"
	"net/http"
	"sync"
	"time"
)

var addr = flag.String("addr", "http://localhost:50052", "the address to connect to")
var vuser = 100

func main() {
	flag.Parse()
	httpClient := &http.Client{
		Transport: &http.Transport{
			MaxIdleConnsPerHost: vuser,
		},
		Timeout: 10 * time.Second, // Set timeout for the HTTP client
	}

	ch := make(chan time.Duration, vuser)

	wg := sync.WaitGroup{}
	for i := 0; i < vuser; i++ {
		go func() {
			wg.Add(1)
			defer wg.Done()
			duration := time.Duration(0)
			for {
				start := time.Now()
				// Making a GET request
				response, err := httpClient.Get(*addr)
				if err != nil {
					duration = time.Since(start)
					fmt.Println(duration, " unexpected error from UnaryEcho: ", err)
					break
				}
				response.Body.Close()
			}
			ch <- duration
		}()
	}
	wg.Wait()
	close(ch)

	total := time.Duration(0)
	for t := range ch {
		total += t
	}
	fmt.Println(total / time.Duration(vuser))
}

graceful shutdown을 썼을 때와 쓰지 않았을 때 에러 응답 시간이 10배 가까이 차이가 남을 확인할 수 있었습니다.