Blog

Testar e colocar em produção uma API REST em Go

Escrito por

Teste uma API REST em Go com httptest, um store fake, verificações de log, o race detector e fuzzing. Depois coloque em produção com timeouts no servidor, graceful shutdown e um único binário estático.

Uma API que passa em algumas requisições curl feitas à mão não está pronta. Você precisa de testes que verifiquem cada status code e cada caminho de erro, e de um servidor que aguente clientes lentos, pare sem perder requisições e vá para produção como algo que você copia para uma máquina e roda.

Este post faz as duas coisas com a API de lista de tarefas construída na parte sobre APIs REST JSON. Ele adiciona arquivos de teste de verdade a esse módulo e depois trata de timeouts, graceful shutdown e do build de um único binário. Todo programa abaixo rodou no Go 1.26, e a saída foi colada da execução.

A API sob teste

A API de tarefas é um módulo Go com um pacote task para o armazenamento, um pacote api para o HTTP e um comando tasksd que roda o servidor. Suas cinco rotas respondem com status codes de 200 a 500, e todo erro é um JSON no mesmo formato. Este post adiciona quatro arquivos de teste ao módulo:

19-tasks-api/
├── go.mod
├── cmd/
│   └── tasksd/
│       ├── main.go
│       └── main_test.go
└── internal/
    ├── task/
    │   ├── task.go
    │   └── memstore.go
    └── api/
        ├── api.go
        ├── api_test.go
        ├── handlers.go
        ├── json.go
        ├── json_test.go
        ├── validate.go
        ├── middleware.go
        └── middleware_test.go

Cada arquivo de teste usa o mesmo nome de pacote do código ao lado, então os testes alcançam nomes não exportados como decodeJSON. A parte sobre pacotes e testes explicou go test, testes table-driven e t.Helper, então este post usa tudo isso sem explicar de novo.

httptest.NewRecorder ou httptest.NewServer

O pacote net/http/httptest dá duas formas de testar um handler, e elas testam coisas diferentes. httptest.NewRecorder retorna um ResponseWriter que guarda o status, os headers e o body. Você mesmo chama ServeHTTP, sem rede. httptest.NewServer inicia um servidor de verdade numa porta de loopback livre, e você fala com ele usando um cliente de verdade.

A maioria dos testes da API usa o recorder, por meio de dois helpers pequenos:

// newTestAPI returns the API over a store that already holds one task,
// "Buy milk", with ID 1. Its logs are thrown away.
func newTestAPI(t *testing.T) http.Handler {
	t.Helper()
	store := task.NewMemStore()
	if _, err := store.Create(t.Context(), task.Task{Title: "Buy milk"}); err != nil {
		t.Fatalf("seeding the store: %v", err)
	}
	return New(store, slog.New(slog.DiscardHandler))
}
// do sends one request straight to h, with no network, and returns
// the recorded response. A non-empty body is sent as JSON.
func do(h http.Handler, method, path, body string) *httptest.ResponseRecorder {
	req := httptest.NewRequest(method, path, strings.NewReader(body))
	if body != "" {
		req.Header.Set("Content-Type", "application/json")
	}
	rec := httptest.NewRecorder()
	h.ServeHTTP(rec, req)
	return rec
}

newTestAPI monta a API inteira, middleware incluído, sobre um store que já tem uma tarefa. slog.DiscardHandler joga os logs fora. t.Context() retorna um context que é cancelado logo antes das funções de cleanup do teste rodarem, então uma chamada ao store num teste recebe esse context, do mesmo jeito que a chamada ao store de um handler recebe r.Context(). Os dois chegaram no Go 1.24.

Use o recorder para testar o que um handler decide: status, headers, body. É rápido, e uma falha aponta direto para o seu código. Use um servidor de verdade quando a rede faz parte do teste: um cliente, o tratamento de conexões, timeouts ou o shutdown.

Uma tabela com todos os endpoints

Um teste table-driven combina bem com uma API, porque cada linha é uma requisição e a resposta que você espera. Este cobre todas as rotas, incluindo os erros:

func TestEndpoints(t *testing.T) {
	tests := []struct {
		name       string
		method     string
		path       string
		body       string
		wantStatus int
		wantHeader map[string]string
		wantBody   string
	}{
		{"list", "GET", "/tasks", "", 200, nil,
			`[{"id":1,"title":"Buy milk","done":false}]`},
		{"get", "GET", "/tasks/1", "", 200, nil,
			`{"id":1,"title":"Buy milk","done":false}`},
		{"get missing", "GET", "/tasks/99", "", 404, nil,
			`{"error":"task not found"}`},
		{"get bad id", "GET", "/tasks/abc", "", 404, nil,
			`{"error":"task not found"}`},
		{"create", "POST", "/tasks", `{"title":"Walk the dog"}`, 201,
			map[string]string{"Location": "/tasks/2"},
			`{"id":2,"title":"Walk the dog","done":false}`},
		{"create blank title", "POST", "/tasks", `{"title":"  "}`, 422, nil,
			`{"error":"validation failed","fields":{"title":"must not be empty"}}`},
		{"create unknown field", "POST", "/tasks", `{"title":"a","id":7}`, 400, nil,
			`{"error":"unknown field \"id\""}`},
		{"create too big", "POST", "/tasks", `{"title":"` + strings.Repeat("a", maxBodyBytes) + `"}`, 413, nil,
			`{"error":"request body must not be larger than 1048576 bytes"}`},
		{"update", "PUT", "/tasks/1", `{"title":"Buy milk","done":true}`, 200, nil,
			`{"id":1,"title":"Buy milk","done":true}`},
		{"update missing", "PUT", "/tasks/99", `{"title":"x"}`, 404, nil,
			`{"error":"task not found"}`},
		{"delete", "DELETE", "/tasks/1", "", 204, nil, ``},
		{"delete missing", "DELETE", "/tasks/99", "", 404, nil,
			`{"error":"task not found"}`},
		{"wrong method", "PATCH", "/tasks/1", "", 405,
			map[string]string{"Allow": "DELETE, GET, HEAD, PUT"},
			`{"error":"method not allowed"}`},
		{"unknown path", "GET", "/users", "", 404, nil,
			`{"error":"not found"}`},
	}
	for _, tt := range tests {
		t.Run(tt.name, func(t *testing.T) {
			rec := do(newTestAPI(t), tt.method, tt.path, tt.body)

			if rec.Code != tt.wantStatus {
				t.Errorf("status = %d, want %d", rec.Code, tt.wantStatus)
			}
			for name, want := range tt.wantHeader {
				if got := rec.Header().Get(name); got != want {
					t.Errorf("%s = %q, want %q", name, got, want)
				}
			}
			if got := strings.TrimSuffix(rec.Body.String(), "\n"); got != tt.wantBody {
				t.Errorf("body = %s, want %s", got, tt.wantBody)
			}
			if rec.Code != http.StatusNoContent {
				if ct := rec.Header().Get("Content-Type"); ct != "application/json" {
					t.Errorf("Content-Type = %q, want application/json", ct)
				}
			}
		})
	}
}

Cada linha ganha uma API nova, então a linha delete não quebra a linha get. Comparar o body inteiro também verifica o formato do erro: fields só aparece no 422, e o 405 é JSON com um header Allow.

Com -v, cada linha aparece como um subtest com nome. Tirei as durações das linhas --- PASS, porque elas mudam a cada execução:

$ go test -v -run TestEndpoints ./internal/api
=== RUN   TestEndpoints
=== RUN   TestEndpoints/list
=== RUN   TestEndpoints/get
=== RUN   TestEndpoints/get_missing
=== RUN   TestEndpoints/get_bad_id
=== RUN   TestEndpoints/create
=== RUN   TestEndpoints/create_blank_title
=== RUN   TestEndpoints/create_unknown_field
=== RUN   TestEndpoints/create_too_big
=== RUN   TestEndpoints/update
=== RUN   TestEndpoints/update_missing
=== RUN   TestEndpoints/delete
=== RUN   TestEndpoints/delete_missing
=== RUN   TestEndpoints/wrong_method
=== RUN   TestEndpoints/unknown_path
--- PASS: TestEndpoints
    --- PASS: TestEndpoints/list
    --- PASS: TestEndpoints/get
    --- PASS: TestEndpoints/get_missing
    --- PASS: TestEndpoints/get_bad_id
    --- PASS: TestEndpoints/create
    --- PASS: TestEndpoints/create_blank_title
    --- PASS: TestEndpoints/create_unknown_field
    --- PASS: TestEndpoints/create_too_big
    --- PASS: TestEndpoints/update
    --- PASS: TestEndpoints/update_missing
    --- PASS: TestEndpoints/delete
    --- PASS: TestEndpoints/delete_missing
    --- PASS: TestEndpoints/wrong_method
    --- PASS: TestEndpoints/unknown_path
PASS

Depois vem uma linha final ok, com uma duração que varia. O caso 415 fica num teste curto próprio, porque precisa de outro Content-Type.

Um servidor de verdade, com t.Cleanup e t.Context

Um teste do pacote da API roda sobre uma conexão de verdade, para verificar que um cliente consegue seguir o header Location de uma criação. Dois helpers preparam isso:

// startServer runs h on a real loopback port until the test ends.
func startServer(t *testing.T, h http.Handler) *httptest.Server {
	t.Helper()
	srv := httptest.NewServer(h)
	t.Cleanup(srv.Close)
	return srv
}
// send makes a real HTTP request and returns the response with its body read.
func send(t *testing.T, method, url, body string) (*http.Response, string) {
	t.Helper()
	req, err := http.NewRequestWithContext(t.Context(), method, url, strings.NewReader(body))
	if err != nil {
		t.Fatalf("building request: %v", err)
	}
	if body != "" {
		req.Header.Set("Content-Type", "application/json")
	}
	resp, err := http.DefaultClient.Do(req)
	if err != nil {
		t.Fatalf("%s %s: %v", method, url, err)
	}
	defer resp.Body.Close()
	b, err := io.ReadAll(resp.Body)
	if err != nil {
		t.Fatalf("reading body: %v", err)
	}
	return resp, strings.TrimSuffix(string(b), "\n")
}

startServer não pode usar defer srv.Close(), porque isso fecharia o servidor assim que o helper retornasse. t.Cleanup(srv.Close) roda o fechamento quando o teste termina. send monta cada requisição com t.Context(), então uma requisição que ainda está esperando quando o teste acaba é cancelada.

func TestCreateThenFollowLocation(t *testing.T) {
	srv := startServer(t, New(task.NewMemStore(), slog.New(slog.DiscardHandler)))

	if _, body := send(t, "GET", srv.URL+"/tasks", ""); body != "[]" {
		t.Fatalf("empty list = %s, want []", body)
	}

	resp, _ := send(t, "POST", srv.URL+"/tasks", `{"title":"Buy milk"}`)
	loc := resp.Header.Get("Location")
	if resp.StatusCode != http.StatusCreated || loc == "" {
		t.Fatalf("create: status %d, Location %q", resp.StatusCode, loc)
	}

	resp, body := send(t, "GET", srv.URL+loc, "")
	if resp.StatusCode != http.StatusOK || body != `{"id":1,"title":"Buy milk","done":false}` {
		t.Errorf("GET %s = %d %s", loc, resp.StatusCode, body)
	}
}

A primeira requisição verifica que uma lista vazia é [], e não null. O resto lê a URL da nova tarefa na resposta, do jeito que um cliente faria.

Um store fake para o caminho do 500

O caminho do 500 é o mais difícil de testar, porque o MemStore nunca falha. Só que Store é uma interface, então um teste pode passar para New qualquer coisa com os cinco métodos. Este fake falha do jeito que o teste escolher:

// fakeStore is a Store whose every method calls fail. The test decides
// what fail does: return an error, or panic.
type fakeStore struct {
	fail func() error
}

func (f fakeStore) List(context.Context) ([]task.Task, error) { return nil, f.fail() }

func (f fakeStore) Get(context.Context, int64) (task.Task, error) { return task.Task{}, f.fail() }

func (f fakeStore) Create(context.Context, task.Task) (task.Task, error) {
	return task.Task{}, f.fail()
}

func (f fakeStore) Update(context.Context, task.Task) (task.Task, error) {
	return task.Task{}, f.fail()
}

func (f fakeStore) Delete(context.Context, int64) error { return f.fail() }

Um teste faz fail retornar um erro, e outro faz entrar em panic. Os handlers não conseguem distinguir isso de um store de verdade, e é justamente para isso que o armazenamento fica atrás de uma interface.

Um 500 tem duas metades que importam. O cliente não pode saber nada sobre a causa, e o log precisa registrar tudo. Para verificar o log, o teste dá à API um logger que escreve num bytes.Buffer:

// newTestLogger returns a logger that writes JSON lines into buf. It drops
// the attributes that change on every run: time, duration and stack.
func newTestLogger(buf *bytes.Buffer) *slog.Logger {
	opts := &slog.HandlerOptions{
		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
			switch a.Key {
			case slog.TimeKey, "duration", "stack":
				return slog.Attr{}
			}
			return a
		},
	}
	return slog.New(slog.NewJSONHandler(buf, opts))
}

O horário, a duração da requisição e o stack trace de um panic mudam a cada execução, então ReplaceAttr descarta esses campos, e o que sobra pode ser comparado exatamente. Aqui está o teste, com o helper dele:

// assertLog fails the test unless buf holds exactly the want lines.
func assertLog(t *testing.T, buf *bytes.Buffer, want ...string) {
	t.Helper()
	got := strings.Split(strings.TrimSuffix(buf.String(), "\n"), "\n")
	if len(got) != len(want) {
		t.Fatalf("got %d log lines, want %d:\n%s", len(got), len(want), buf)
	}
	for i := range want {
		if got[i] != want[i] {
			t.Errorf("log line %d:\n got %s\nwant %s", i+1, got[i], want[i])
		}
	}
}
func TestStoreErrorIs500(t *testing.T) {
	var logs bytes.Buffer
	store := fakeStore{fail: func() error {
		return errors.New("dial tcp db.internal:5432: connection refused")
	}}
	h := New(store, newTestLogger(&logs))

	rec := do(h, "GET", "/tasks/1", "")

	if rec.Code != http.StatusInternalServerError {
		t.Errorf("status = %d, want 500", rec.Code)
	}
	if body := rec.Body.String(); body != `{"error":"internal server error"}`+"\n" {
		t.Errorf("body = %q leaks more than it should", body)
	}
	assertLog(t, &logs,
		`{"level":"ERROR","msg":"internal error","err":"dial tcp db.internal:5432: connection refused","request_id":"req-1"}`,
		`{"level":"INFO","msg":"request","method":"GET","path":"/tasks/1","status":500,"request_id":"req-1"}`,
	)
}

O erro cita o host e a porta de um banco de dados, que um atacante adoraria ver. O body é só {"error":"internal server error"}. O log tem o erro real e depois a linha da requisição com status 500, e as duas carregam req-1, que leva do relato de bug de um usuário até a causa.

Testando a recuperação de panics e os request IDs

A recuperação de panics também é testada com o fakeStore, desta vez com um fail que entra em panic:

func TestPanicIs500(t *testing.T) {
	var logs bytes.Buffer
	store := fakeStore{fail: func() error { panic("store exploded") }}
	h := New(store, newTestLogger(&logs))

	rec := do(h, "DELETE", "/tasks/1", "")

	if rec.Code != http.StatusInternalServerError {
		t.Errorf("status = %d, want 500", rec.Code)
	}
	if body := rec.Body.String(); strings.Contains(body, "exploded") {
		t.Errorf("body = %q leaks the panic value", body)
	}
	if id := rec.Header().Get("X-Request-Id"); id != "req-1" {
		t.Errorf("X-Request-Id = %q, want req-1", id)
	}
	assertLog(t, &logs,
		`{"level":"ERROR","msg":"panic","value":"store exploded","request_id":"req-1"}`,
		`{"level":"INFO","msg":"request","method":"DELETE","path":"/tasks/1","status":500,"request_id":"req-1"}`,
	)
}

O panic começa dentro do store e passa pela cadeia de middleware real que New monta. Se alguém reordenar New de modo que logRequests fique dentro de recoverPanics, a linha da requisição some do log e este teste falha.

Um panic depois que o status já foi enviado é outra história:

func TestPanicAfterWriteHeader(t *testing.T) {
	var logs bytes.Buffer
	s := &server{logger: newTestLogger(&logs)}
	h := s.recoverPanics(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		w.WriteHeader(http.StatusOK)
		fmt.Fprint(w, "[")
		panic("encoder broke halfway")
	}))

	rec := do(h, "GET", "/tasks", "")

	// The 200 is already on its way, so the recovery can't turn it into a 500.
	if rec.Code != http.StatusOK {
		t.Errorf("status = %d, want 200", rec.Code)
	}
	if want := `[{"error":"internal server error"}` + "\n"; rec.Body.String() != want {
		t.Errorf("body = %q, want %q", rec.Body.String(), want)
	}
}

Este teste chama recoverPanics diretamente, com um handler que envia um 200 e um byte e depois entra em panic. A recuperação ainda chama writeError, mas WriteHeader(500) chega tarde demais, então o status continua 200. O JSON de erro é acrescentado ao que já foi enviado, e o cliente recebe [{"error":"internal server error"}, que não é JSON válido. É por isso que writeJSON serializa o body inteiro antes de escrever um status. O teste fixa esse comportamento, para ninguém achar que a recuperação cobre esse caso.

TestRequestIDs, no mesmo arquivo, envia três requisições e verifica req-1, req-2 e req-3, depois verifica que um segundo New recomeça em req-1.

O race detector em requisições concorrentes

O race detector observa a memória enquanto os testes rodam e reporta duas goroutines mexendo na mesma variável sem um lock. Ele só enxerga código que de fato roda ao mesmo tempo, então o teste precisa fazer isso acontecer:

func TestConcurrentCreates(t *testing.T) {
	h := New(task.NewMemStore(), slog.New(slog.DiscardHandler))

	const n = 50
	var wg sync.WaitGroup
	for range n {
		wg.Go(func() {
			rec := do(h, "POST", "/tasks", `{"title":"Buy milk"}`)
			if rec.Code != http.StatusCreated {
				t.Errorf("status = %d, want 201", rec.Code)
			}
		})
	}
	wg.Wait()

	var tasks []task.Task
	rec := do(h, "GET", "/tasks", "")
	if err := json.NewDecoder(rec.Body).Decode(&tasks); err != nil {
		t.Fatalf("decoding list: %v", err)
	}
	if len(tasks) != n {
		t.Fatalf("got %d tasks, want %d", len(tasks), n)
	}
	for i, tk := range tasks {
		if tk.ID != int64(i+1) {
			t.Errorf("tasks[%d].ID = %d, want %d", i, tk.ID, i+1)
		}
	}
}

Cinquenta goroutines enviam POST /tasks para um mesmo handler ao mesmo tempo, usando sync.WaitGroup.Go, do Go 1.25. Depois o teste verifica que há exatamente cinquenta tarefas, com IDs de 1 a 50. t.Errorf pode ser chamado com segurança dessas goroutines, mas t.Fatalf precisa rodar na goroutine do próprio teste.

Para ver o teste fazer o trabalho dele, apaguei as duas linhas que travam o mutex em MemStore.Create e rodei com -race. Aqui estão as linhas do relatório que não mudam entre execuções, com a duração removida da linha --- FAIL:

$ go test -race -run TestConcurrentCreates ./internal/api
==================
WARNING: DATA RACE
...
  example.com/tasks/internal/task.(*MemStore).Create()
...
--- FAIL: TestConcurrentCreates
    testing.go:1712: race detected during execution of test
FAIL

O race detector apontou o problema em 20 de 20 execuções. Sem -race, 19 execuções quebraram com fatal error: concurrent map writes e uma passou. Essa única passada é o motivo para rodar go test -race ./... antes de toda release: um race que não quebra hoje continua sendo um bug.

Fuzzing no decoder

Um fuzz test entrega a uma função milhares de entradas geradas e verifica uma propriedade que precisa valer para todas elas. decodeJSON lê bytes de estranhos, então é o alvo natural:

// FuzzDecodeJSON feeds decodeJSON random bodies. Whatever arrives, it must
// not panic, and every error must be a *requestError with a 4xx status.
func FuzzDecodeJSON(f *testing.F) {
	f.Add(`{"title":"Buy milk","done":true}`)
	f.Add(`{"title":`)
	f.Add(`["Buy milk"]`)
	f.Add(`{"title":"a"}{"title":"b"}`)

	f.Fuzz(func(t *testing.T, body string) {
		req := httptest.NewRequest("POST", "/tasks", strings.NewReader(body))
		req.Header.Set("Content-Type", "application/json")

		var in taskInput
		err := decodeJSON(httptest.NewRecorder(), req, &in)
		if err == nil {
			return
		}
		var re *requestError
		if !errors.As(err, &re) {
			t.Fatalf("decodeJSON(%q) returned %T, want *requestError", body, err)
		}
		if re.status != http.StatusBadRequest && re.status != http.StatusRequestEntityTooLarge {
			t.Fatalf("decodeJSON(%q) status = %d, want 400 or 413", body, re.status)
		}
	})
}

Qualquer que seja o body, decodeJSON não pode entrar em panic, e qualquer erro precisa ser um *requestError com 400 ou 413. As chamadas a f.Add são seeds que o fuzzer vai modificar. Um go test comum roda só as seeds. Para gerar entradas novas, passe -fuzz com um limite de tempo:

$ go test -fuzz=FuzzDecodeJSON -fuzztime=10s ./internal/api
fuzz: elapsed: 0s, gathering baseline coverage: 0/4 completed
...
PASS

As linhas de progresso no meio dependem da sua máquina. Uma entrada que falhasse seria salva em testdata/fuzz/FuzzDecodeJSON/, e o go test comum passaria a rodá-la como seed a partir daí. -fuzz aceita um pacote de cada vez, então ./... é recusado.

Contra o que cada timeout do servidor protege

Um http.Server sem timeouts espera um cliente lento para sempre, e cada cliente esperando segura uma conexão e uma goroutine. O servidor em cmd/tasksd define quatro:

	srv := &http.Server{
		Handler:           handler,
		ReadHeaderTimeout: 5 * time.Second,
		ReadTimeout:       10 * time.Second,
		WriteTimeout:      10 * time.Second,
		IdleTimeout:       60 * time.Second,
		ErrorLog:          slog.NewLogLogger(logger.Handler(), slog.LevelError),
	}

Em palavras simples, cada um limita um tipo diferente de espera:

  • ReadHeaderTimeout para um cliente que envia os headers da requisição muito devagar, ou nunca termina de enviá-los. Esse é o ataque Slowloris: abrir milhares de conexões, mandar alguns bytes em cada uma de vez em quando, e o servidor fica sem conexões sem nunca ver uma requisição completa.
  • ReadTimeout limita a leitura da requisição inteira, body incluído, então um cliente também não consegue ir pingando um body para sempre.
  • WriteTimeout limita quanto tempo a resposta pode levar, contado a partir do fim dos headers da requisição. Ele para um cliente que lê a resposta devagar demais e põe um teto na requisição inteira.
  • IdleTimeout fecha uma conexão keep-alive que ficou parada sem uso entre requisições.

Este programa envia metade de um header de requisição e depois espera, uma vez contra um servidor sem ReadHeaderTimeout e outra contra um de 50ms. O cliente espera 2 segundos, uma margem folgada:

package main

import (
	"errors"
	"fmt"
	"net"
	"net/http"
	"net/http/httptest"
	"os"
	"time"
)

// slowClient connects, sends half a request header, and then waits up to
// 2 seconds for the server to do anything.
func slowClient(timeout time.Duration) {
	h := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		fmt.Fprintln(w, "hello")
	})
	srv := httptest.NewUnstartedServer(h)
	srv.Config.ReadHeaderTimeout = timeout
	srv.Start()
	defer srv.Close()

	conn, err := net.Dial("tcp", srv.Listener.Addr().String())
	if err != nil {
		fmt.Println(err)
		return
	}
	defer conn.Close()
	fmt.Fprint(conn, "GET / HTTP/1.1\r\nHost: example.com\r\n") // no blank line: the header never ends

	conn.SetReadDeadline(time.Now().Add(2 * time.Second))
	_, err = conn.Read(make([]byte, 1))
	switch {
	case errors.Is(err, os.ErrDeadlineExceeded):
		fmt.Printf("ReadHeaderTimeout %v: after 2s the server is still holding the connection open\n", timeout)
	default:
		fmt.Printf("ReadHeaderTimeout %v: the server hung up: %v\n", timeout, err)
	}
}

func main() {
	slowClient(0)
	slowClient(50 * time.Millisecond)
}

Ele imprime:

ReadHeaderTimeout 0s: after 2s the server is still holding the connection open
ReadHeaderTimeout 50ms: the server hung up: EOF

Com o timeout, o servidor fechou a conexão sem enviar nada, nem mesmo um 408, e recuperou a conexão.

O WriteTimeout me surpreendeu. Eu esperava que ele parasse um handler lento, e ele não para:

package main

import (
	"errors"
	"fmt"
	"io"
	"net/http"
	"net/http/httptest"
	"time"
)

func main() {
	handlerDone := make(chan string, 1)
	h := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		time.Sleep(500 * time.Millisecond) // slow work, 10 times the WriteTimeout
		_, err := fmt.Fprintln(w, "report ready")
		handlerDone <- fmt.Sprintf("handler: finished, write error = %v", err)
	})
	srv := httptest.NewUnstartedServer(h)
	srv.Config.WriteTimeout = 50 * time.Millisecond
	srv.Start()
	defer srv.Close()

	_, err := http.Get(srv.URL)
	fmt.Println("client got EOF:", errors.Is(err, io.EOF))
	fmt.Println(<-handlerDone)
}

Ele imprime:

client got EOF: true
handler: finished, write error = <nil>

O handler rodou seus 500ms inteiros, e a escrita dele não reportou erro, porque os bytes só foram para o buffer do servidor. O timeout agiu quando o servidor tentou enviá-los, e o cliente recebeu uma conexão fechada em vez de uma resposta. O WriteTimeout protege a conexão, não o tempo do seu handler. Para desistir de um trabalho lento, passe r.Context() para ele, ou envolva o handler em http.TimeoutHandler, que responde 503 quando o tempo acaba.

Graceful shutdown

Parar um servidor matando o processo corta todas as requisições no meio. Um graceful shutdown para de aceitar conexões novas, deixa as requisições que já estão rodando terminarem e só então sai. Esta é a segunda metade de serve em cmd/tasksd:

	errc := make(chan error, 1)
	go func() {
		logger.Info("listening", "addr", ln.Addr().String())
		errc <- srv.Serve(ln)
	}()

	select {
	case err := <-errc:
		return err
	case <-ctx.Done():
	}

	logger.Info("shutting down")
	shutdownCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
	defer cancel()
	if err := srv.Shutdown(shutdownCtx); err != nil {
		return err
	}
	if err := <-errc; !errors.Is(err, http.ErrServerClosed) {
		return err
	}
	return nil
}

A sequência tem cinco passos:

  1. srv.Serve(ln) bloqueia até o servidor parar, então roda numa goroutine. errc tem espaço para um valor, então essa goroutine sempre consegue enviar o resultado e sair.
  2. O select espera o que acontecer primeiro: Serve falhar, ou ctx ser cancelado, o que o signal.NotifyContext em run faz no Ctrl+C ou no SIGTERM.
  3. srv.Shutdown fecha o listener, então conexões novas são recusadas, fecha as conexões ociosas e espera as ativas terminarem suas requisições.
  4. A espera ganha um context novo de 10 segundos a partir de context.Background(), porque ctx já está cancelado e encerraria a espera na hora. Se ainda houver requisições rodando no prazo, Shutdown retorna context.DeadlineExceeded.
  5. Depois do Shutdown, Serve retorna http.ErrServerClosed. Esse é o jeito normal de parar, então serve retorna nil nesse caso.

Mantenha os 10 segundos abaixo do tempo que a sua plataforma espera entre o SIGTERM e matar o processo. O Kubernetes espera 30 segundos por padrão, mas o docker stop espera só 10.

Explicado como se você tivesse dez anos

Pense numa loja na hora de fechar. A dona não empurra todo mundo para a rua. Primeiro ela tranca a porta da frente, para ninguém novo entrar. Quem está só olhando, sem comprar, é convidado a sair. Os clientes que já estão no caixa podem terminar de pagar.

Quando o último cliente paga, ela apaga as luzes e vai para casa. Se alguém ainda estiver contando moedas depois de dez minutos, ela fecha mesmo assim.

A versão precisa

Shutdown fecha todos os listeners registrados no servidor, então o sistema operacional recusa conexões novas naquela porta. Depois fecha as conexões ociosas, ou seja, as que estão entre requisições, ou as novas que passaram alguns segundos sem começar uma requisição. Então verifica periodicamente as conexões restantes e retorna quando todas terminaram a requisição atual e ficaram ociosas, ou quando o context dele acaba. Ele não cancela os contexts das requisições e não interrompe handlers. Um handler que nunca retorna deixa Shutdown esperando até o prazo.

Onde a analogia falha: a dona da loja pode dizer a um cliente “estamos fechando, por favor, se apresse”. Shutdown não avisa nada aos handlers que estão rodando. Se um handler faz um trabalho longo, ele precisa saber do shutdown de outro jeito, por exemplo por uma função registrada com srv.RegisterOnShutdown. Além disso, trancar a porta não é educado numa rede de verdade: um cliente que tenta conectar recebe “connection refused”, então um load balancer deve parar de mandar tráfego antes de o shutdown começar.

ctx cancelado: Shutdown começa última req. acaba: Shutdown retorna listener aceitando fechou recusa ociosa keep-alive fecha na hora req. A handler rodando respondeu serve() srv.Serve(ln) em Shutdown retorna nil

O graceful shutdown ao longo do tempo. Quando ctx é cancelado, o listener fecha e conexões novas são recusadas, as conexões ociosas fecham na hora, e Shutdown espera até a requisição que já estava rodando enviar sua resposta.

Provando num teste que o shutdown funciona

Não dá para verificar a sequência de shutdown rodando main e apertando Ctrl+C num teste, mas serve recebe um context, um listener e um handler, então um teste consegue conduzir cada passo. Ele escuta em 127.0.0.1:0, que pede ao sistema operacional qualquer porta livre, e passa para serve um handler que fica bloqueado até o teste liberá-lo:

func TestServeShutsDownGracefully(t *testing.T) {
	ln, err := net.Listen("tcp", "127.0.0.1:0")
	if err != nil {
		t.Fatal(err)
	}
	addr := ln.Addr().String()

	started := make(chan struct{})
	release := make(chan struct{})
	slow := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		close(started)
		<-release
		io.WriteString(w, "finished")
	})

	ctx, cancel := context.WithCancel(t.Context())
	served := make(chan error, 1)
	go func() {
		served <- serve(ctx, ln, slow, slog.New(slog.DiscardHandler))
	}()

	// 1. Start a request, and wait until the handler is running.
	type result struct {
		body string
		err  error
	}
	inflight := make(chan result, 1)
	go func() {
		resp, err := http.Get("http://" + addr + "/slow")
		if err != nil {
			inflight <- result{err: err}
			return
		}
		defer resp.Body.Close()
		b, err := io.ReadAll(resp.Body)
		inflight <- result{string(b), err}
	}()
	<-started

	// 2. Ask the server to stop, as SIGTERM would.
	cancel()

	// 3. Wait until new connections are refused. Shutdown closes the
	// listener first, but nothing tells us when, so poll with a deadline.
	deadline := time.Now().Add(5 * time.Second)
	for {
		conn, err := net.Dial("tcp", addr)
		if err != nil {
			break
		}
		conn.Close()
		if time.Now().After(deadline) {
			t.Fatal("server still accepts connections 5s after cancel")
		}
		time.Sleep(10 * time.Millisecond)
	}

	// 4. The request in flight has not been cut off. Let it finish.
	select {
	case r := <-inflight:
		t.Fatalf("request ended before it was released: %+v", r)
	default:
	}
	close(release)

	if r := <-inflight; r.err != nil || r.body != "finished" {
		t.Errorf("in-flight request: body %q, err %v; want finished", r.body, r.err)
	}
	if err := <-served; err != nil {
		t.Errorf("serve returned %v, want nil", err)
	}
}

Quem fixa a ordem são os channels, não sleeps. O handler fecha started assim que roda, então o teste só cancela quando a requisição está mesmo em andamento, e o handler não consegue terminar até o teste fechar release.

Um passo precisa fazer polling, porque Shutdown não sinaliza quando o listener fecha. O teste tenta conectar a cada 10 milissegundos até uma conexão falhar, com um prazo de 5 segundos, e fecha cada conexão que passa para o Shutdown não ficar esperando por ela.

Um teste que não pode falhar não prova nada, então troquei srv.Shutdown(shutdownCtx) por srv.Close(), que fecha todas as conexões de uma vez. O teste falhou: a requisição em andamento recebeu EOF em vez de finished.

O teste passou 20 vezes seguidas com go test -race -count=20 ./.... Ele não usa testing/synctest, estável desde o Go 1.25: esse pacote simula o relógio, mas a documentação dele diz para evitar rede de verdade lá dentro.

Colocando um único binário em produção

Um programa Go vira um único executável que inclui o runtime e todos os pacotes que ele usa, então colocar a API em produção é copiar um arquivo. Primeiro, dê uma versão a ele: main.go declara uma variável que o build pode sobrescrever.

// version is set at build time with -ldflags "-X main.version=v1.2.3".
var version = "dev"

func main() {
	addr := flag.String("addr", "localhost:8080", "address to listen on")
	showVersion := flag.Bool("version", false, "print the version and exit")
	flag.Parse()

	if *showVersion {
		fmt.Println("tasksd", version)
		return
	}

	logger := slog.New(slog.NewJSONHandler(os.Stderr, nil))
	if err := run(*addr, logger); err != nil {
		logger.Error("server stopped", "err", err)
		os.Exit(1)
	}
}

-X main.version=v1.0.0 define essa string na hora do link. Este é o build de release:

$ CGO_ENABLED=0 go build -trimpath -ldflags="-s -w -X main.version=v1.0.0" -o tasksd ./cmd/tasksd
$ ./tasksd -version
tasksd v1.0.0

O que cada flag faz:

  • CGO_ENABLED=0 desliga o cgo. Isso me surpreendeu: um go build comum do servidor saiu com link dinâmico para a biblioteca C, mesmo sem o módulo ter código C. O pacote net pode usar a biblioteca C para consultas DNS, então ele a linka sempre que o cgo está disponível. Com o cgo desligado, o file reportou um binário com link estático, que roda em qualquer Linux daquela arquitetura, até num container vazio.
  • -trimpath remove do binário os caminhos de diretório da sua máquina, então stack traces mostram example.com/tasks/internal/api/handlers.go em vez de um caminho na sua pasta pessoal. Também ajuda duas máquinas a gerarem os mesmos bytes a partir do mesmo código.
  • -ldflags="-s -w" descarta a tabela de símbolos e as informações de debug DWARF. O build de release saiu cerca de um terço menor que um go build comum. Panics ainda imprimem nomes de arquivo e números de linha, porque o runtime guarda tabelas próprias para isso, mas um debugger tem menos com o que trabalhar.

go version -m lê de volta as configurações de build de qualquer binário Go:

$ go version -m tasksd
...
	path	example.com/tasks/cmd/tasksd
	mod	example.com/tasks	(devel)	
	build	-buildmode=exe
	build	-compiler=gc
	build	-trimpath=true
	build	CGO_ENABLED=0
	build	GOARCH=amd64
	build	GOOS=linux
	build	GOAMD64=v1

Deixei de fora a primeira linha, que cita a release exata do Go. -ldflags não aparece na lista: o Go não registra essa flag com -trimpath, porque flags do linker podem conter caminhos. Um programa pode ler a mesma informação com debug.ReadBuildInfo, mas para o seu próprio número de versão, -X é mais simples.

Para compilar para outro sistema, defina GOOS e GOARCH. Não precisa de nenhum toolchain extra:

$ CGO_ENABLED=0 GOOS=linux GOARCH=arm64 go build -trimpath -ldflags="-s -w" -o tasksd-linux-arm64 ./cmd/tasksd
$ GOOS=windows GOARCH=amd64 go build -trimpath -ldflags="-s -w" -o tasksd.exe ./cmd/tasksd

go tool dist list imprime todos os pares suportados. Quando mandei SIGTERM para o binário Linux com kill, ele registrou shutting down no log e saiu com status 0.

Um binário estático também gera uma imagem de container pequena. Este Dockerfile é ilustrativo. Não fiz o build nem rodei ele como parte deste post:

FROM golang:1.26 AS build
WORKDIR /src
COPY . .
RUN CGO_ENABLED=0 go build -trimpath -ldflags="-s -w" -o /tasksd ./cmd/tasksd

FROM scratch
COPY --from=build /tasksd /tasksd
USER 65532:65532
ENTRYPOINT ["/tasksd", "-addr", ":8080"]

A imagem final só tem o binário: nada de shell, nada de certificados de CA, nada de dados de fuso horário. Este servidor não precisa de nenhum deles, mas um serviço que chama APIs HTTPS precisaria de certificados, ou de uma imagem base distroless. O -addr :8080 importa, porque localhost:8080 só aceita conexões de dentro do container. A forma exec do ENTRYPOINT faz do tasksd o processo 1, então o docker stop envia o SIGTERM direto para ele.

Para onde ir daqui

A API de tarefas é um serviço pequeno e completo, e cada próximo passo já tem lugar no design:

  • Um banco de dados. Escreva um Store sobre database/sql, como o esboço de SQLStore na parte sobre APIs JSON, e rode a mesma tabela de endpoints contra ele com um banco de teste.
  • Autenticação. Um middleware que verifica um token e coloca o usuário no context da requisição, o mesmo padrão de withRequestID. Para clientes de navegador, veja http.CrossOriginProtection, adicionado no Go 1.25, que rejeita requisições cross-origin inseguras.
  • Uma descrição OpenAPI das rotas, dos bodies e dos status codes, para os clientes gerarem código a partir dela.
  • Profiling. net/http/pprof serve profiles de CPU e de memória. Coloque numa porta separada e privada, nunca no mux público.

O que lembrar

  • Teste handlers com httptest.NewRecorder para status, headers e body. Use httptest.NewServer quando a rede, um cliente ou o próprio servidor faz parte do teste.
  • Coloque o armazenamento atrás de uma interface, e um fake pequeno consegue provocar todo caminho de erro, incluindo um panic. Verifique o log também, com um handler de slog escrevendo num buffer e ReplaceAttr descartando o que muda.
  • Use t.Cleanup em helpers em vez de defer, e t.Context() para tudo que recebe um context. Rode go test -race ./... com testes que realmente enviam requisições ao mesmo tempo.
  • Defina ReadHeaderTimeout contra clientes lentos. WriteTimeout fecha a conexão, mas não para o seu handler.
  • Faça o shutdown com srv.Shutdown e um prazo, e trate http.ErrServerClosed como sucesso. Teste isso com um handler que bloqueia num channel.
  • Coloque em produção com CGO_ENABLED=0 go build -trimpath -ldflags="-s -w", defina a versão com -X e faça compilação cruzada com GOOS e GOARCH.

Um servidor não está pronto até você testar como ele falha e como ele para.

Quanto este post te ajudou?

Clique em um coração para avaliar!

Média das avaliações 0 / 5. Total de votos: 0

Nenhum voto até agora. Seja o primeiro a avaliar este post.