🤖 fix: aggregated writes treat a proxy 3xx and a build answer without the requested build as uncertain

docs/reference/aggregated-api-behavior.md

@@ -229,8 +229,10 @@ A Coder call that runs out of time returns `504 Gateway Timeout` on every aggreg
 A write (create, update, patch, or delete) of a workspace or a template can also get an answer that leaves its result open, for example from a proxy in front of Coder. Coder can have applied the write. The server returns `504`, with a message that says that the result is uncertain, for these answers:
 
 - A `502` or a `503`.
+- An error answer that is not in Coder's own format, a JSON body with a message. Examples are an HTML page with `400`, `409`, or `500` from a proxy, an empty body, and JSON without a message. The server takes only an error answer in Coder's format as Coder's refusal (see the trust assumption below).
 - A `2xx` that Coder does not send: a status other than the expected one, or a body that is not the expected JSON. Examples on a create are a `201` with an HTML page, an empty body, invalid JSON, or a JSON array, and a `200` with an HTML page, invalid JSON, or the JSON of Coder.
-- An answer without the object that the server needs: a create answer without the ID or name of the object, a build answer of a workspace update or delete without the ID of the build, a template version answer of a template create or files update without the ID of the version, or a template update answer without the template. An example is a `200` or `201` with `{}` or `null`.
+- An answer without the object that the server needs: a create answer without the ID or name of the object, a build answer of a workspace update or delete without the ID of the build or the requested transition, a template version answer of a template create or files update without the ID of the version, or a template update answer without the template. An example is a `200` or `201` with `{}` or `null`, or a build answer with only an ID.
+- A `3xx` that the HTTP client of the server does not follow, for example a redirect without `Location` from a proxy. The server that sent it got the write.
 - A redirect to another origin, which the server refuses, or a redirect whose next request fails. The server that sent the redirect got the write.
 - A template files update whose activation Coder accepted, when the re-read of the template fails or shows another active version.
 - A template update that changed the files or the metadata in Coder, when the read of the template that ends the update fails.
@@ -248,6 +250,17 @@ A write that the server knows did not reach Coder keeps the `500` that says that
 
 The server cannot tell other transport errors without a status apart from a connection that broke after the send. It treats them as uncertain and returns the `504`.
 
+A workspace create with `spec.running=false` creates the workspace and then requests a stop build. When the stop request fails, or its answer has no build ID or another transition (for example `201` with `{}`), the server re-reads the workspace. The result depends on the stop request:
+
+- A stop that can have reached Coder (an uncertain answer from the list above, or a timeout): only a stop build with an ID and a status in the re-read confirms it, and the create returns that build. A re-read that fails or still shows the start build returns `504` with a message that says that the result is uncertain, because Coder can still be queueing the stop. The workspace exists in Coder, but the server cannot say whether it is stopping. Re-read it with `kubectl get` before you do anything else. Do not retry the create, because the workspace exists. To stop the workspace, update `spec.running`.
+- A stop that Coder refused (an error answer in Coder's format), or that did not reach Coder, leaves the start build. The create succeeds and returns the latest build of the re-read, a start or stop build with an ID and a status, or the start build of the create when the re-read fails. Retry the stop with an update.
+
+### Limits of the checks
+
+- **Trust assumption: nothing between the server and Coder forges a well-formed Coder JSON answer.** The server checks the shape of each answer, as listed above, but not where it came from. A proxy that forges a well-formed answer can make the server report a wrong result. A success answer with a made-up build ID and the requested transition, or a template update answer with the right template ID and the old metadata, makes the server report success although Coder did not apply the write. An error answer in Coder's format (JSON with a message) that a proxy sends after Coder applied the write makes the server report Coder's refusal, for example `400` or `409`. Coder itself does not send such answers. Put only proxies that forward requests and answers unchanged between the server and Coder.
+- **Partly written HTTP/1.1 headers.** A connection that fails while the HTTP/1.1 client writes the request headers can deliver a part of them to Coder before the client records the headers as written. The write error is not one of the not-sent errors above, so the write still returns the uncertain `504`.
+- **HTTP/2 retries.** The Go HTTP/2 client sends a request again on a new connection after Coder or a proxy resets the stream with `PROTOCOL_ERROR` ([golang/go#47635](https://github.com/golang/go/issues/47635)). When that retry succeeds, Coder can get the write twice, for example two builds or two template versions, and the server reports one success. This applies only to `https` Coder URLs that negotiate HTTP/2. An in-cluster `http` Coder URL uses HTTP/1.1. This is Go behavior, and the server does not detect or prevent it.
+
 A `get` or a `list` that gets a Coder object without its ID or the fields of its name, for example `{}`, returns `500` with a message that contains `the Coder API answered`.
 
 The message does not include the Coder URL. The same is true for a `403` that Coder answers, a `500` for a Coder server error, and a `500` when the server cannot reach Coder. These messages name only the resource, the object and the Coder status code. The server log keeps the full Coder error, on a line from the `coder-errors` logger.
@@ -468,8 +481,8 @@ Other status codes:
 
 One time budget of 25 seconds covers every Coder call of a request: the lookup, the build request, the re-read after a Coder `409`, and the confirming re-read after an uncertain build request. The calls before the confirming re-read must end within 20 seconds, so at least 5 seconds stay for it. Each call also ends after the Coder request timeout (`--coder-request-timeout`, 30 seconds by default).
 
-- If Coder answers `409` to the build request, another build started after the lookup. The server re-reads the workspace one time. If the latest build already does what you asked, the outcome is `InProgress` or `Unchanged`. Otherwise the server returns `409` with the message from Coder.
-- If the build request times out, fails on the network, gets `502`, `503`, or `504` (for example from a proxy in front of Coder), or gets an answer without the ID of the build (for example `201` with `{}`), the server cannot know whether Coder queued the build. It re-reads the workspace one time, in the rest of the budget. If the latest build is a new build of the requested kind, started by the operator user of the control plane, and of the template version that the request sent (if it sent one), the outcome is `Queued`. A build that another user started in the meantime, for example in the Coder UI, does not count. Otherwise, or when the server cannot read the operator user, it returns `504`, and the message says that the result is uncertain.
+- If Coder answers `409` to the build request, another build started after the lookup. The server re-reads the workspace one time. If the latest build already does what you asked, the outcome is `InProgress` or `Unchanged`. Otherwise the server returns `409` with the message from Coder. If the re-read fails, the server returns the uncertain `504`, because a proxy can also send a `409` in Coder's format.
+- If the build request times out, fails on the network, gets `502`, `503`, or `504` (for example from a proxy in front of Coder), gets a `3xx` that the HTTP client does not follow, gets an error answer that is not in Coder's own format (for example an HTML page with `409` or `500`), or gets an answer without the ID of the build or with another transition (for example `201` with `{}` or with only an ID), the server cannot know whether Coder queued the build. It re-reads the workspace one time, in the rest of the budget. If the latest build is a new build of the requested kind, with an ID and a status, started by the operator user of the control plane, and of the template version that the request sent (if it sent one), the outcome is `Queued`. A build that another user started in the meantime, for example in the Coder UI, does not count. Otherwise, or when the server cannot read the operator user, or when the re-read answer is not a valid workspace (for example without its name), it returns `504`, and the message says that the result is uncertain.
 - Known gap: if the operator user itself starts a matching build somewhere else in that window, for example with its token in the Coder CLI, the server cannot tell the two builds apart. It then answers `Queued` and names that build.
 - After a `504`, re-read the latest build of the workspace (`status.latestBuildID` and `status.latestBuildStatus` of the `CoderWorkspace`) before you retry.
 - The server never sends a second build request by itself.

internal/aggregated/coder/errors.go

@@ -115,16 +115,31 @@ const (
 // a write. A 2xx status means that the request got through, but the answer is not the one that
 // Coder sends: the SDK returns a *codersdk.Error for a 2xx other than the expected one, and since
 // codersdk v2.37 also for the expected 2xx with a body that is not JSON (for example a proxy page
-// or an empty body). A proxy in front of Coder can answer 502, 503 or 504 after Coder applied the
-// write.
+// or an empty body). The SDK sees a 3xx only when net/http did not follow it, for example a proxy
+// redirect without Location, and the server that answered it got the write. A proxy in front of
+// Coder can answer 502, 503 or 504 after Coder applied the write.
 func IsUncertainStatus(status int) bool {
-	return (status >= http.StatusOK && status < http.StatusMultipleChoices) ||
+	return (status >= http.StatusOK && status < http.StatusBadRequest) ||
 		status == http.StatusBadGateway || status == http.StatusServiceUnavailable || status == http.StatusGatewayTimeout
 }
 
+// IsCoderErrorAnswer reports whether coderErr comes from an error answer in Coder's own format: a
+// JSON body with a message. For a body that is not JSON, is empty, or has no message, for example
+// the error page of a proxy, the SDK sets one of its own messages instead.
+func IsCoderErrorAnswer(coderErr *codersdk.Error) bool {
+	if coderErr == nil {
+		panic("assertion failed: coder error must not be nil")
+	}
+	message := coderErr.Message
+	return message != "" && message != "empty response body" &&
+		!strings.HasPrefix(message, "unexpected non-JSON response ") &&
+		message != fmt.Sprintf("unexpected status code %d, response has no message", coderErr.StatusCode())
+}
+
 // MapCoderWriteError maps the error of the Coder call that creates, updates or deletes name. An
 // error that leaves it open whether Coder applied the write returns UncertainWriteError: a status
-// of IsUncertainStatus other than 504, or an error without a status after the request was sent,
+// of IsUncertainStatus other than 504, an error answer that is not Coder's own (see
+// IsCoderErrorAnswer), or an error without a status after the request was sent,
 // such as a connection that broke or a body that is not the expected JSON. A timeout, a Coder 504,
 // a request that did not reach Coder (see notSent) and every other status map as in MapCoderError.
 func MapCoderWriteError(err error, write Write, resource schema.GroupResource, name string) error {
@@ -144,7 +159,7 @@ func MapCoderWriteError(err error, write Write, resource schema.GroupResource, n
 	var coderErr *codersdk.Error
 	if errors.As(err, &coderErr) {
 		status := coderErr.StatusCode()
-		if status != http.StatusGatewayTimeout && IsUncertainStatus(status) {
+		if status != http.StatusGatewayTimeout && (IsUncertainStatus(status) || !IsCoderErrorAnswer(coderErr)) {
 			logHiddenError(err, resource, name, status)
 			return UncertainWriteError(write, resource, name, fmt.Sprintf("status %d from the Coder API", status))
 		}
@@ -159,6 +174,27 @@ func MapCoderWriteError(err error, write Write, resource schema.GroupResource, n
 	return UncertainWriteError(write, resource, name, "an answer from the Coder API that broke off or could not be read")
 }
 
+// UncertainWriteErrorFrom is UncertainWriteError for a write whose result the Coder call that
+// failed with err could not confirm. It logs err, which names the Coder URL, for operators.
+func UncertainWriteErrorFrom(err error, write Write, resource schema.GroupResource, name, reason string) error {
+	if err == nil {
+		return fmt.Errorf("assertion failed: error must not be nil")
+	}
+	LogHiddenError(err, resource, name)
+	return UncertainWriteError(write, resource, name, reason)
+}
+
+// LogHiddenError logs err, which can name the Coder URL, for operators, with the status of its
+// *codersdk.Error or 0 for an error without a status.
+func LogHiddenError(err error, resource schema.GroupResource, name string) {
+	status := 0
+	var coderErr *codersdk.Error
+	if errors.As(err, &coderErr) {
+		status = coderErr.StatusCode()
+	}
+	logHiddenError(err, resource, name, status)
+}
+
 // UncertainWriteError is the 504 for a write that Coder can have applied. reason names the answer
 // that the write got, for example "status 502 from the Coder API", and must not name the Coder
 // URL. The error has no Retry-After, so clients do not send the write again on their own.

internal/aggregated/coder/errors_log_test.go

@@ -0,0 +1,64 @@
+package coder
+
+import (
+	"errors"
+	"fmt"
+	"net/http"
+	"net/url"
+	"strings"
+	"sync"
+	"testing"
+
+	"github.com/coder/coder/v2/codersdk"
+	"github.com/go-logr/logr/funcr"
+
+	aggregationv1alpha1 "github.com/coder/coder-k8s/api/aggregation/v1alpha1"
+)
+
+// TestMappedErrorsLogTheFullError: the messages for a Coder 403, a Coder 500, an unreachable Coder
+// and an uncertain write leave out the Coder URL, and the coder-errors log keeps the full error.
+// It replaces errorLog, so it does not run in parallel.
+func TestMappedErrorsLogTheFullError(t *testing.T) {
+	var mu sync.Mutex
+	var lines []string
+	previous := errorLog
+	errorLog = funcr.New(func(_, args string) {
+		mu.Lock()
+		defer mu.Unlock()
+		lines = append(lines, args)
+	}, funcr.Options{Verbosity: 1})
+	t.Cleanup(func() { errorLog = previous })
+
+	resource := aggregationv1alpha1.Resource("coderworkspaces")
+	const coderURL = "https://coder.internal.example.com/api/v2/workspaces/1234"
+	withMessage := func(status int) error {
+		coderErr := codersdk.NewTestError(status, http.MethodPost, coderURL)
+		coderErr.Message = "Coder says no."
+		return coderErr
+	}
+	for _, tc := range []struct {
+		name string
+		err  error
+	}{
+		{"Coder 403", MapCoderError(withMessage(http.StatusForbidden), resource, "acme.alice.a")},
+		{"Coder 500", MapCoderError(withMessage(http.StatusInternalServerError), resource, "acme.alice.b")},
+		{"unreachable", MapCoderError(&url.Error{Op: "Get", URL: coderURL, Err: errors.New("connection refused")}, resource, "acme.alice.c")},
+		{"uncertain write", MapCoderWriteError(withMessage(http.StatusBadGateway), WriteCreate, resource, "acme.alice.d")},
+	} {
+		if strings.Contains(tc.err.Error(), "coder.internal.example.com") {
+			t.Fatalf("%s: the message %q names the Coder URL", tc.name, tc.err.Error())
+		}
+	}
+
+	mu.Lock()
+	defer mu.Unlock()
+	for _, name := range []string{"acme.alice.a", "acme.alice.b", "acme.alice.c", "acme.alice.d"} {
+		found := false
+		for _, line := range lines {
+			found = found || (strings.Contains(line, fmt.Sprintf("%q", name)) && strings.Contains(line, "coder.internal.example.com"))
+		}
+		if !found {
+			t.Fatalf("the coder-errors log has no line with the full error for %s: %q", name, lines)
+		}
+	}
+}

internal/aggregated/coder/errors_test.go

@@ -278,6 +278,12 @@ func TestMapCoderWriteError(t *testing.T) {
 		{"204", sdkErr(http.StatusNoContent), uncertain},
 		{"proxy 502", sdkErr(http.StatusBadGateway), uncertain},
 		{"proxy 503", sdkErr(http.StatusServiceUnavailable), uncertain},
+		// net/http returns a 3xx without Location instead of following it. The server that
+		// answered got the write.
+		{"300", sdkErr(http.StatusMultipleChoices), uncertain},
+		{"307 without Location", sdkErr(http.StatusTemporaryRedirect), uncertain},
+		// Without a message, the error answer is not Coder's own, for example a proxy page.
+		{"500 without a Coder message", sdkErr(http.StatusInternalServerError), uncertain},
 		{"body breaks off", fmt.Errorf("read response body: %w", io.ErrUnexpectedEOF), uncertain},
 		{"malformed JSON on an unexpected 2xx", fmt.Errorf("decode body: %w", &json.SyntaxError{}), uncertain},
 		{"connection closed without an answer", afterSend(io.EOF), uncertain},
@@ -319,9 +325,9 @@ func TestMapCoderWriteError(t *testing.T) {
 		}
 	}
 
-	// A Coder answer with a status that leaves no doubt maps as in MapCoderError.
-	for _, status := range []int{http.StatusConflict, http.StatusBadRequest, http.StatusInternalServerError, http.StatusMultipleChoices} {
-		err := sdkErr(status)
+	// A Coder error answer with a status that leaves no doubt maps as in MapCoderError.
+	for _, status := range []int{http.StatusConflict, http.StatusBadRequest, http.StatusInternalServerError} {
+		err := withCoderMessage(codersdk.NewTestError(status, http.MethodPost, coderURL), "Coder refused the write.")
 		got, want := MapCoderWriteError(err, WriteCreate, resource, name), MapCoderError(err, resource, name)
 		if got.Error() != want.Error() || apierrors.ReasonForError(got) != apierrors.ReasonForError(want) {
 			t.Fatalf("%d: expected the MapCoderError mapping %v, got %v", status, want, got)

internal/aggregated/coder/errors_transport_test.go

@@ -315,3 +315,60 @@ func h2ResetServer(t *testing.T, received *atomic.Int32) (string, *tls.Config) {
 	}()
 	return "https://" + listener.Addr().String(), clientTLS
 }
+
+// TestMapCoderWriteErrorPartlyWrittenHeaders: the server reads a part of the request headers and
+// resets the connection before net/http records the headers as written. The write error is not one
+// that proves the request was not sent, so the write returns the uncertain 504.
+func TestMapCoderWriteErrorPartlyWrittenHeaders(t *testing.T) {
+	t.Parallel()
+
+	listener, err := net.Listen("tcp", "127.0.0.1:0")
+	if err != nil {
+		t.Fatal(err)
+	}
+	t.Cleanup(func() { _ = listener.Close() })
+	received := make(chan int, 1)
+	go func() {
+		conn, err := listener.Accept()
+		if err != nil {
+			received <- -1
+			return
+		}
+		defer func() { _ = conn.Close() }()
+		_ = conn.SetDeadline(time.Now().Add(5 * time.Second))
+		n, _ := io.ReadFull(conn, make([]byte, 4096))
+		received <- n
+		_ = conn.(*net.TCPConn).SetLinger(0)
+	}()
+
+	base, err := url.Parse("http://" + listener.Addr().String())
+	if err != nil {
+		t.Fatal(err)
+	}
+	transport, err := newCoderTransport()
+	if err != nil {
+		t.Fatal(err)
+	}
+	transport.Proxy = nil
+	t.Cleanup(transport.CloseIdleConnections)
+	req, err := http.NewRequestWithContext(context.Background(), http.MethodPost, base.String()+"/api/v2/workspaces", strings.NewReader(`{"name":"dev"}`))
+	if err != nil {
+		t.Fatal(err)
+	}
+	// A header far larger than what the server reads, so the reset comes while net/http writes it.
+	req.Header.Set(codersdk.SessionTokenHeader, strings.Repeat("x", 16<<20))
+	resp, err := newCoderHTTPClient(base, transport, 10*time.Second).Do(req)
+	if resp != nil {
+		_ = resp.Body.Close()
+	}
+	if err == nil {
+		t.Fatal("expected the reset connection to fail the request")
+	}
+	if n := <-received; n <= 0 {
+		t.Fatalf("the server received %d bytes of the request, want some", n)
+	}
+	mapped := MapCoderWriteError(err, WriteCreate, aggregationv1alpha1.Resource("coderworkspaces"), "acme.alice.dev")
+	if !apierrors.IsTimeout(mapped) || !strings.Contains(mapped.Error(), "uncertain") {
+		t.Fatalf("expected the uncertain 504, got %v (from %v)", mapped, err)
+	}
+}