smallwebwaf/internal/proxy/timeouts_test.go

package proxy_test

import (
	"errors"
	"io"
	"net"
	"net/http"
	"strconv"
	"sync"
	"testing"
	"time"

	"sneak.berlin/go/smallwebwaf/internal/requestlog"
)

// largeBodySize is more than the connections between the client,
// smallwebwaf and the app can hold while nobody reads, so that a sender
// soon waits.
const largeBodySize = 64 << 20

// writeSize is how much a test sender writes at a time.
const writeSize = 32 << 10

func TestRequestTimeouts(t *testing.T) {
	t.Parallel()

	for _, tc := range []struct {
		name string
		env  map[string]string
		// appTakesNothing has the app never read, while the client sends
		// as fast as it can; otherwise the app reads, and the client
		// stops sending halfway.
		appTakesNothing bool
		want            int
	}{
		{
			name: "client request timeout, waiting on the client",
			env:  map[string]string{clientRequestTimeout: shortTimeoutSetting},
			want: http.StatusRequestTimeout,
		},
		{
			name: "upstream request timeout, waiting on the client",
			env: map[string]string{
				upstreamRequestTimeout: shortTimeoutSetting,
				clientRequestTimeout:   longTimeoutSetting,
			},
			want: http.StatusRequestTimeout,
		},
		{
			name:            "upstream request timeout, waiting on the app",
			env:             map[string]string{upstreamRequestTimeout: shortTimeoutSetting},
			appTakesNothing: true,
			want:            http.StatusGatewayTimeout,
		},
		{
			name: "client request timeout, waiting on the app",
			env: map[string]string{
				clientRequestTimeout:   shortTimeoutSetting,
				upstreamRequestTimeout: longTimeoutSetting,
			},
			appTakesNothing: true,
			want:            http.StatusGatewayTimeout,
		},
	} {
		t.Run(tc.name, func(t *testing.T) {
			t.Parallel()

			var (
				appURL      string
				sendRequest func(*testing.T, string) net.Conn
			)

			if tc.appTakesNothing {
				appURL, sendRequest = startAppThatTakesNothing(t), sendLargeBody
			} else {
				appURL, sendRequest = startApp(t, readBody).URL, sendPartOfBody
			}

			addr, out := startProxy(t, appURL, tc.env)
			start := time.Now()
			conn := sendRequest(t, addr)

			wantStatus(t, readResponse(t, conn), tc.want)
			wantTimedOut(t, start)
			wantLine(t, out.requestLine(t), tc.want, requestlog.ActionTimedOut)
		})
	}
}

// readBody is an app that reads the request body, then answers.
func readBody(_ http.ResponseWriter, r *http.Request) {
	_, _ = io.Copy(io.Discard, r.Body)
}

// startAppThatTakesNothing starts an app that accepts connections and
// never reads from them, and returns its URL.
func startAppThatTakesNothing(t *testing.T) string {
	t.Helper()

	listener, err := (&net.ListenConfig{}).Listen(t.Context(), "tcp", localhost+":0")
	if err != nil {
		t.Fatalf("listen: %v", err)
	}

	var (
		mu   sync.Mutex
		held []net.Conn
	)

	hold := func(conn net.Conn) {
		mu.Lock()
		defer mu.Unlock()

		held = append(held, conn)
	}

	go func() {
		for {
			conn, err := listener.Accept()
			if err != nil {
				return
			}

			hold(conn)
		}
	}()

	t.Cleanup(func() {
		_ = listener.Close()

		mu.Lock()
		defer mu.Unlock()

		for _, conn := range held {
			_ = conn.Close()
		}
	})

	return "http://" + listener.Addr().String()
}

// sendPartOfBody sends a request that announces a large body, and only
// the first bytes of it.
func sendPartOfBody(t *testing.T, addr string) net.Conn {
	t.Helper()

	conn := dial(t, addr)
	send(t, conn, "POST /upload HTTP/1.1\r\nHost: app\r\nContent-Length: "+
		strconv.Itoa(largeBodySize)+"\r\n\r\nthe first bytes")

	return conn
}

// sendLargeBody sends a request with a large body, as fast as smallwebwaf
// takes it, from a goroutine of its own.
func sendLargeBody(t *testing.T, addr string) net.Conn {
	t.Helper()

	conn := dial(t, addr)
	send(t, conn, "POST /upload HTTP/1.1\r\nHost: app\r\nContent-Length: "+
		strconv.Itoa(largeBodySize)+"\r\n\r\n")

	go func() {
		chunk := make([]byte, writeSize)
		for range largeBodySize / writeSize {
			_, err := conn.Write(chunk)
			if err != nil {
				return
			}
		}
	}()

	return conn
}

func TestAppTooSlowToAnswer(t *testing.T) {
	t.Parallel()

	app := startApp(t, func(_ http.ResponseWriter, r *http.Request) {
		<-r.Context().Done()
	})
	addr, out := startProxy(t, app.URL, map[string]string{
		upstreamResponseTimeout: shortTimeoutSetting,
	})

	start := time.Now()

	wantStatus(t, get(t, addr, "/slow"), http.StatusGatewayTimeout)
	wantTimedOut(t, start)

	line := out.requestLine(t)
	wantLine(t, line, http.StatusGatewayTimeout, requestlog.ActionTimedOut)

	_, answered := line.fields["upstream_status"]
	if answered {
		t.Errorf("log line has upstream_status %v for an app that never answered",
			line.fields["upstream_status"])
	}
}

func TestAppTooSlowToFinishItsAnswer(t *testing.T) {
	t.Parallel()

	app := startApp(t, func(w http.ResponseWriter, r *http.Request) {
		_, _ = io.WriteString(w, "the first part")
		_ = http.NewResponseController(w).Flush()

		<-r.Context().Done()
	})
	addr, out := startProxy(t, app.URL, map[string]string{
		upstreamResponseTimeout: shortTimeoutSetting,
	})

	start := time.Now()
	got := get(t, addr, "/slow")
	wantStatus(t, got, http.StatusOK)

	if string(got.body) != "the first part" || !errors.Is(got.err, io.ErrUnexpectedEOF) {
		t.Errorf("client read %q (%v), want the first part cut off", got.body, got.err)
	}

	wantTimedOut(t, start)

	line := out.requestLine(t)
	wantLine(t, line, http.StatusOK, requestlog.ActionTimedOut)

	if line.UpstreamStatus != http.StatusOK {
		t.Errorf("log line has upstream_status %d, want %d",
			line.UpstreamStatus, http.StatusOK)
	}
}

func TestClientTooSlowToTakeTheAnswer(t *testing.T) {
	t.Parallel()

	app := startApp(t, func(w http.ResponseWriter, _ *http.Request) {
		chunk := make([]byte, writeSize)
		for range largeBodySize / writeSize {
			_, err := w.Write(chunk)
			if err != nil {
				return
			}
		}
	})
	addr, out := startProxy(t, app.URL, map[string]string{
		clientResponseTimeout: shortTimeoutSetting,
	})

	start := time.Now()

	// The client asks, and never reads the answer.
	conn := dial(t, addr)
	send(t, conn, "GET /large HTTP/1.1\r\nHost: app\r\n\r\n")

	line := out.requestLine(t)
	wantTimedOut(t, start)
	wantLine(t, line, http.StatusOK, requestlog.ActionTimedOut)
}