diff --git a/docs/reference/aggregated-api-behavior.md b/docs/reference/aggregated-api-behavior.md index 5d37296d..16018c39 100644 --- a/docs/reference/aggregated-api-behavior.md +++ b/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. diff --git a/internal/aggregated/coder/errors.go b/internal/aggregated/coder/errors.go index 27127d1c..6ea81ed1 100644 --- a/internal/aggregated/coder/errors.go +++ b/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. diff --git a/internal/aggregated/coder/errors_log_test.go b/internal/aggregated/coder/errors_log_test.go new file mode 100644 index 00000000..ab9bb70f --- /dev/null +++ b/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) + } + } +} diff --git a/internal/aggregated/coder/errors_test.go b/internal/aggregated/coder/errors_test.go index f4f2f0e5..4da7b944 100644 --- a/internal/aggregated/coder/errors_test.go +++ b/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) diff --git a/internal/aggregated/coder/errors_transport_test.go b/internal/aggregated/coder/errors_transport_test.go index 9141611f..532d9da0 100644 --- a/internal/aggregated/coder/errors_transport_test.go +++ b/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) + } +} diff --git a/internal/aggregated/storage/errors.go b/internal/aggregated/storage/errors.go index e78ea6bd..09a0bf3e 100644 --- a/internal/aggregated/storage/errors.go +++ b/internal/aggregated/storage/errors.go @@ -4,6 +4,8 @@ import ( "errors" "fmt" + "github.com/coder/coder/v2/codersdk" + "github.com/google/uuid" apierrors "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/runtime" @@ -38,10 +40,17 @@ func uncertainCreateAnswer(resource schema.GroupResource, name string) error { return coder.UncertainWriteError(coder.WriteCreate, resource, name, "an answer from the Coder API without the ID or name of the object") } +// isRequestedBuild reports whether build, the answer to a build POST with transition, is a build +// that Coder queued for it. Coder answers with the new build, which has an ID and the requested +// transition. An answer from a proxy, for example {} or a body with only an ID, does not. +func isRequestedBuild(build codersdk.WorkspaceBuild, transition codersdk.WorkspaceTransition) bool { + return build.ID != uuid.Nil && build.Transition == transition +} + // uncertainBuildAnswer is the error for a workspace update or delete whose build request Coder -// answered with its success status, but without a build, for example with {} from a proxy. +// answered with its success status, but without the requested build (see isRequestedBuild). func uncertainBuildAnswer(write coder.Write, name string) error { - return coder.UncertainWriteError(write, aggregationv1alpha1.Resource("coderworkspaces"), name, "an answer from the Coder API without the ID of the build") + return coder.UncertainWriteError(write, aggregationv1alpha1.Resource("coderworkspaces"), name, "an answer from the Coder API without the requested build") } func wrapClientError(err error) error { diff --git a/internal/aggregated/storage/storage_test.go b/internal/aggregated/storage/storage_test.go index 600afd57..ffd42a3a 100644 --- a/internal/aggregated/storage/storage_test.go +++ b/internal/aggregated/storage/storage_test.go @@ -2935,6 +2935,9 @@ func (s *mockCoderServerState) handleRequest(t *testing.T, w http.ResponseWriter case r.Method == http.MethodGet && hasSegments(segments, "api", "v2", "workspaces") && len(segments) == 3: s.handleListWorkspaces(w) return + case r.Method == http.MethodGet && hasSegments(segments, "api", "v2", "workspaces") && len(segments) == 4: + s.handleGetWorkspaceByID(w, segments[3]) + return case r.Method == http.MethodGet && hasSegments(segments, "api", "v2", "users") && len(segments) == 6 && segments[4] == "workspace": s.handleGetWorkspace(w, segments[3], segments[5]) return @@ -3542,6 +3545,24 @@ func (s *mockCoderServerState) handleGetWorkspace(w http.ResponseWriter, owner, writeJSON(w, http.StatusOK, workspace) } +func (s *mockCoderServerState) handleGetWorkspaceByID(w http.ResponseWriter, workspaceIDSegment string) { + s.mu.Lock() + defer s.mu.Unlock() + + workspaceID, err := uuid.Parse(workspaceIDSegment) + if err != nil { + writeCoderError(w, http.StatusBadRequest, fmt.Sprintf("invalid workspace id %q", workspaceIDSegment)) + return + } + workspace, ok := s.workspacesByID[workspaceID] + if !ok { + writeCoderError(w, http.StatusNotFound, "workspace not found") + return + } + + writeJSON(w, http.StatusOK, workspace) +} + func (s *mockCoderServerState) handleCreateWorkspace(w http.ResponseWriter, r *http.Request, user string) { s.mu.Lock() defer s.mu.Unlock() diff --git a/internal/aggregated/storage/template.go b/internal/aggregated/storage/template.go index 7952a66c..66b4450c 100644 --- a/internal/aggregated/storage/template.go +++ b/internal/aggregated/storage/template.go @@ -786,7 +786,7 @@ func (s *TemplateStorage) Update( // so a re-read that fails or shows another version leaves the result open. verifyTemplate, err := sdk.Template(ctx, templateID) if err != nil { - return nil, false, coder.UncertainWriteError(coder.WriteUpdate, aggregationv1alpha1.Resource("codertemplates"), name, + return nil, false, coder.UncertainWriteErrorFrom(err, coder.WriteUpdate, aggregationv1alpha1.Resource("codertemplates"), name, "no re-read of the template from the Coder API after the activation") } if verifyTemplate.ActiveVersionID != newVersion.ID { diff --git a/internal/aggregated/storage/workspace.go b/internal/aggregated/storage/workspace.go index 120857a7..b6ce0f48 100644 --- a/internal/aggregated/storage/workspace.go +++ b/internal/aggregated/storage/workspace.go @@ -2,6 +2,7 @@ package storage import ( "context" + "errors" "fmt" "sort" "sync" @@ -481,11 +482,33 @@ func (s *WorkspaceStorage) Create( stopBuild, stopErr := sdk.CreateWorkspaceBuild(ctx, createdWorkspace.ID, codersdk.CreateWorkspaceBuildRequest{ Transition: codersdk.WorkspaceTransitionStop, }) - if stopErr == nil { + if stopErr == nil && isRequestedBuild(stopBuild, codersdk.WorkspaceTransitionStop) { createdWorkspace.LatestBuild = stopBuild + } else { + // Without the stop build in the answer, Coder can still have queued the stop, or still be + // queueing it while the re-read shows the start build. Only the stop build confirms such + // a stop. The start build is the result only after a stop that Coder refused or that was + // not sent. + stopUncertain := stopErr == nil || + apierrors.IsTimeout(coder.MapCoderWriteError(stopErr, coder.WriteCreate, aggregationv1alpha1.Resource("coderworkspaces"), workspaceObj.Name)) + current, readErr := sdk.Workspace(ctx, createdWorkspace.ID) + latest := current.LatestBuild + confirms := latest.Transition == codersdk.WorkspaceTransitionStop || + (!stopUncertain && latest.Transition == codersdk.WorkspaceTransitionStart) + if readErr == nil && (latest.ID == uuid.Nil || latest.Status == "" || !confirms) { + readErr = errors.New("the re-read of the workspace shows no confirming build with an ID and a status") + } + switch { + case readErr == nil: + createdWorkspace.LatestBuild = latest + case stopUncertain: + // The start build of the create answer can be stale, so it is not a result. + return nil, coder.UncertainWriteErrorFrom(readErr, coder.WriteCreate, aggregationv1alpha1.Resource("coderworkspaces"), workspaceObj.Name, + "no confirmation of its stop build from the Coder API after the workspace was created") + } } - // The workspace creation already succeeded. Returning a stop transition error here - // would cause client retries to fail with AlreadyExists, while the desired stop + // The workspace creation already succeeded. Returning an error for a stop that Coder + // refused would cause client retries to fail with AlreadyExists, while the desired stop // transition can be retried safely via a subsequent Update. } @@ -692,7 +715,7 @@ func (s *WorkspaceStorage) Update( if err != nil { return nil, false, coder.MapCoderWriteError(err, coder.WriteUpdate, aggregationv1alpha1.Resource("coderworkspaces"), name) } - if build.ID == uuid.Nil { + if !isRequestedBuild(build, req.Transition) { return nil, false, uncertainBuildAnswer(coder.WriteUpdate, name) } @@ -777,7 +800,7 @@ func (s *WorkspaceStorage) Delete( if err != nil { return nil, false, coder.MapCoderWriteError(err, coder.WriteDelete, aggregationv1alpha1.Resource("coderworkspaces"), name) } - if deleteBuild.ID == uuid.Nil { + if !isRequestedBuild(deleteBuild, codersdk.WorkspaceTransitionDelete) { return nil, false, uncertainBuildAnswer(coder.WriteDelete, name) } diff --git a/internal/aggregated/storage/workspace_transition.go b/internal/aggregated/storage/workspace_transition.go index a6dc99a3..0f245252 100644 --- a/internal/aggregated/storage/workspace_transition.go +++ b/internal/aggregated/storage/workspace_transition.go @@ -144,28 +144,26 @@ func (s *WorkspaceTransitionStorage) Create( } } newBuild, err := sdk.CreateWorkspaceBuild(callCtx, workspace.ID, req) - if err == nil && newBuild.ID != uuid.Nil { + if err == nil && isRequestedBuild(newBuild, req.Transition) { return s.queued(namespace, name, workspace, newBuild) } var coderErr *codersdk.Error - isCoderErr := errors.As(err, &coderErr) + refused := errors.As(err, &coderErr) && !coder.IsUncertainStatus(coderErr.StatusCode()) && coder.IsCoderErrorAnswer(coderErr) switch { - case isCoderErr && coderErr.StatusCode() == http.StatusConflict: + case refused && coderErr.StatusCode() == http.StatusConflict: return s.afterConflict(callCtx, sdk, namespace, name, workspace.ID, coderErr) - case !isCoderErr || coder.IsUncertainStatus(coderErr.StatusCode()): - // A timeout, a transport error, a gateway error, or an answer without the build ID - // leaves it open whether Coder queued the build: a proxy in front of Coder can fail - // after Coder accepted it. Never POST again: one confirming re-read either finds the + case !refused: + // A timeout, a transport error, a gateway error, an error answer that is not Coder's own, + // or an answer without the requested build leaves it open whether Coder queued the build: + // a proxy in front of Coder can fail after Coder accepted it. Never POST again: one confirming re-read either finds the // new build or reports the doubt. The re-read gets the rest of the budget, at least // confirmTimeout. current, rereadErr := sdk.Workspace(budgetCtx, workspace.ID) if rereadErr == nil && confirmsPost(budgetCtx, sdk, workspace.LatestBuild.ID, current.LatestBuild, req) { return s.queued(namespace, name, current, current.LatestBuild) } - return nil, apierrors.NewTimeoutError(fmt.Sprintf( - "the result is uncertain: the Coder API did not confirm the %s build in time; re-read the workspace's latest build before you retry", - s.transition), 0) + return nil, s.uncertain() default: return nil, coder.MapCoderError(err, aggregationv1alpha1.Resource("coderworkspaces"), name) } @@ -177,7 +175,7 @@ func (s *WorkspaceTransitionStorage) Create( // queued in the meantime (for example in the Coder UI) does not confirm it. If the operator // user itself queued a matching build elsewhere in that window, the two cannot be told apart. func confirmsPost(ctx context.Context, sdk *codersdk.Client, previousID uuid.UUID, found codersdk.WorkspaceBuild, req codersdk.CreateWorkspaceBuildRequest) bool { - if found.ID == previousID || found.Transition != req.Transition { + if found.ID == uuid.Nil || found.ID == previousID || found.Status == "" || found.Transition != req.Transition { return false } if req.TemplateVersionID != uuid.Nil && found.TemplateVersionID != req.TemplateVersionID { @@ -188,7 +186,9 @@ func confirmsPost(ctx context.Context, sdk *codersdk.Client, previousID uuid.UUI } // afterConflict handles a Coder 409 on the build POST: another build became active after the -// lookup. One re-read decides whether that build already does what was requested. +// lookup. One re-read decides whether that build already does what was requested. A 409 in Coder's +// format can also come from a proxy after Coder queued the build, so a failed re-read leaves the +// result open. func (s *WorkspaceTransitionStorage) afterConflict( ctx context.Context, sdk *codersdk.Client, @@ -198,7 +198,8 @@ func (s *WorkspaceTransitionStorage) afterConflict( ) (runtime.Object, error) { current, err := sdk.Workspace(ctx, workspaceID) if err != nil { - return nil, coder.MapCoderError(err, aggregationv1alpha1.Resource("coderworkspaces"), name) + coder.LogHiddenError(err, aggregationv1alpha1.Resource("coderworkspaces"), name) + return nil, s.uncertain() } outcome, err := decideTransition(s.transition, name, current.LatestBuild) if err != nil && !apierrors.IsConflict(err) { @@ -211,13 +212,21 @@ func (s *WorkspaceTransitionStorage) afterConflict( fmt.Errorf("%s; retry after the active build ends", coderErr.Message)) } +// uncertain is the 504 for a build request that Coder can have applied without a confirmation. +func (s *WorkspaceTransitionStorage) uncertain() error { + return apierrors.NewTimeoutError(fmt.Sprintf( + "the result is uncertain: the Coder API did not confirm the %s build; re-read the workspace's latest build before you retry", + s.transition), 0) +} + // queued answers Queued for a build that this request queued. Like an update of spec.running, it -// sends a Modified watch event for the workspace with that build as the latest build. +// sends a Modified watch event for the workspace with that build as the latest build. The build +// request was sent, so a workspace that does not convert leaves the result open. func (s *WorkspaceTransitionStorage) queued(namespace, name string, workspace codersdk.Workspace, build codersdk.WorkspaceBuild) (runtime.Object, error) { workspace.LatestBuild = build obj, err := convert.WorkspaceToK8s(namespace, workspace) if err != nil { - return nil, apierrors.NewInternalError(err) + return nil, s.uncertain() } s.workspaces.enqueueWatchEvent(watch.Modified, obj) return s.result(namespace, name, transitionOutcomeQueued, false, &build), nil diff --git a/internal/aggregated/storage/workspace_transition_test.go b/internal/aggregated/storage/workspace_transition_test.go index 9dc2d36e..fef061a1 100644 --- a/internal/aggregated/storage/workspace_transition_test.go +++ b/internal/aggregated/storage/workspace_transition_test.go @@ -199,8 +199,18 @@ func runTransition(t *testing.T, s *WorkspaceTransitionStorage, dryRun bool) (*a return result, nil } +// build returns a build with the job status and a workspace status that matches it. func build(transition codersdk.WorkspaceTransition, status codersdk.ProvisionerJobStatus) codersdk.WorkspaceBuild { - return codersdk.WorkspaceBuild{Transition: transition, Job: codersdk.ProvisionerJob{Status: status}} + workspaceStatus := codersdk.WorkspaceStatusPending + switch { + case status == codersdk.ProvisionerJobSucceeded && transition == codersdk.WorkspaceTransitionStart: + workspaceStatus = codersdk.WorkspaceStatusRunning + case status == codersdk.ProvisionerJobSucceeded && transition == codersdk.WorkspaceTransitionStop: + workspaceStatus = codersdk.WorkspaceStatusStopped + case status == codersdk.ProvisionerJobFailed: + workspaceStatus = codersdk.WorkspaceStatusFailed + } + return codersdk.WorkspaceBuild{Transition: transition, Status: workspaceStatus, Job: codersdk.ProvisionerJob{Status: status}} } const ( @@ -498,6 +508,8 @@ func TestWorkspaceTransitionUncertainPost(t *testing.T) { {"a proxy answered 200 with an HTML page", stop, false, nil, http.StatusOK, false, ""}, {"a proxy answered 201 with {} after the build was queued", stop, false, &found{transition: stop}, http.StatusCreated, true, "{}"}, {"a proxy answered 201 with null", stop, false, nil, http.StatusCreated, false, "null"}, + {"a proxy answered 201 with only a build ID", stop, false, nil, http.StatusCreated, false, `{"id":"` + uuid.NewString() + `"}`}, + {"a proxy answered 307 without Location after the build was queued", stop, false, &found{transition: stop}, http.StatusTemporaryRedirect, true, ""}, {"another user queued the same transition", stop, false, &found{transition: stop, byOther: true}, 0, false, ""}, {"the new build has the other transition", stop, false, &found{transition: start}, 0, false, ""}, {"a start with the requested version", start, true, &found{transition: start}, 0, true, ""}, @@ -636,6 +648,67 @@ func TestWorkspaceTransitionUncertainPost(t *testing.T) { } } +// TestWorkspaceTransitionMalformedConfirmingReRead: Coder queued the build, the POST answer leaves +// it open, and the confirming re-read fails or does not show a usable new build: a workspace +// without its name, a latest build without its ID or its status. The re-read does not confirm the +// build, so the result is the uncertain 504, not a 500 and not Queued. A 409 that is not Coder's own +// answer leaves the result open in the same way. +func TestWorkspaceTransitionMalformedConfirmingReRead(t *testing.T) { + writeWorkspace := func(change func(*codersdk.Workspace)) func(http.ResponseWriter, codersdk.Workspace) { + return func(w http.ResponseWriter, current codersdk.Workspace) { + change(¤t) + writeLogFakeJSON(w, current) + } + } + for _, tc := range []struct { + name string + post func(http.ResponseWriter) + reRead func(http.ResponseWriter, codersdk.Workspace) + }{ + {"307, workspace without its name", gatewayPageWriter(http.StatusTemporaryRedirect), writeWorkspace(func(ws *codersdk.Workspace) { ws.Name = "" })}, + {"502, workspace without its name", gatewayPageWriter(http.StatusBadGateway), writeWorkspace(func(ws *codersdk.Workspace) { ws.Name = "" })}, + {"307, latest build without its ID", gatewayPageWriter(http.StatusTemporaryRedirect), writeWorkspace(func(ws *codersdk.Workspace) { ws.LatestBuild.ID = uuid.Nil })}, + {"502, latest build without its ID", gatewayPageWriter(http.StatusBadGateway), writeWorkspace(func(ws *codersdk.Workspace) { ws.LatestBuild.ID = uuid.Nil })}, + {"307, latest build without its status", gatewayPageWriter(http.StatusTemporaryRedirect), writeWorkspace(func(ws *codersdk.Workspace) { ws.LatestBuild.Status = "" })}, + {"502, latest build without its status", gatewayPageWriter(http.StatusBadGateway), writeWorkspace(func(ws *codersdk.Workspace) { ws.LatestBuild.Status = "" })}, + {"proxy 409 page, re-read 502", gatewayPageWriter(http.StatusConflict), func(w http.ResponseWriter, _ codersdk.Workspace) { writeLogFakeError(w, http.StatusBadGateway) }}, + {"409 that looks like Coder's, re-read 502", func(w http.ResponseWriter) { writeLogFakeError(w, http.StatusConflict) }, func(w http.ResponseWriter, _ codersdk.Workspace) { + writeLogFakeError(w, http.StatusBadGateway) + }}, + } { + f := newTransitionFakeCoder(t, build(codersdk.WorkspaceTransitionStart, codersdk.ProvisionerJobSucceeded)) + queued := build(codersdk.WorkspaceTransitionStop, codersdk.ProvisionerJobPending) + queued.ID, queued.BuildNumber, queued.InitiatorID = uuid.New(), 8, f.operatorID + f.set(func(f *transitionFakeCoder) { + f.onPost = func(w http.ResponseWriter, _ *http.Request) { + f.update(func(ws *codersdk.Workspace) { ws.LatestBuild = queued }) + tc.post(w) + } + f.onReread = func(w http.ResponseWriter, _ *http.Request) { + f.mu.Lock() + current := f.ws + f.mu.Unlock() + tc.reRead(w, current) + } + }) + result, err := runTransition(t, newTestTransitionStorage(t, f, codersdk.WorkspaceTransitionStop), false) + if posts, _ := f.recordedPosts(); len(posts) != 1 || f.rereads.Load() != 1 { + t.Fatalf("%s: POSTs=%d rereads=%d, want 1 and 1", tc.name, len(posts), f.rereads.Load()) + } + if !apierrors.IsTimeout(err) || !strings.Contains(err.Error(), "uncertain") || !strings.Contains(err.Error(), "re-read") { + t.Fatalf("%s: result=%v err=%v, want an uncertain 504", tc.name, result, err) + } + } +} + +func gatewayPageWriter(status int) func(http.ResponseWriter) { + return func(w http.ResponseWriter) { + w.Header().Set("Content-Type", "text/html") + w.WriteHeader(status) + _, _ = w.Write([]byte("proxy page")) + } +} + // TestWorkspaceTransitionRequestChecks covers the body, identity checks, and Coder errors. func TestWorkspaceTransitionRequestChecks(t *testing.T) { f := newTransitionFakeCoder(t, build(codersdk.WorkspaceTransitionStop, codersdk.ProvisionerJobSucceeded)) @@ -730,3 +803,31 @@ func TestWorkspaceTransitionQueuedSendsWatchEvent(t *testing.T) { } assertNoWatchEvent(t, watcher, 200*time.Millisecond) } + +// TestWorkspaceTransitionConflictReReadFailureIsLogged: after a 409 in Coder's format, the re-read +// fails. The client gets the uncertain 504, and the coder-errors log keeps the re-read error. +func TestWorkspaceTransitionConflictReReadFailureIsLogged(t *testing.T) { + t.Parallel() + + marker := uuid.NewString() + f := newTransitionFakeCoder(t, build(codersdk.WorkspaceTransitionStart, codersdk.ProvisionerJobSucceeded)) + f.set(func(f *transitionFakeCoder) { + f.onPost = func(w http.ResponseWriter, _ *http.Request) { writeLogFakeError(w, http.StatusConflict) } + f.onReread = func(w http.ResponseWriter, _ *http.Request) { + w.Header().Set("Content-Type", "application/json") + w.WriteHeader(http.StatusServiceUnavailable) + _ = json.NewEncoder(w).Encode(codersdk.Response{Message: marker}) + } + }) + readLog := captureCoderErrorLog() + _, err := runTransition(t, newTestTransitionStorage(t, f, codersdk.WorkspaceTransitionStop), false) + if !apierrors.IsTimeout(err) || !strings.Contains(err.Error(), "uncertain") || f.rereads.Load() != 1 { + t.Fatalf("err=%v rereads=%d, want the uncertain 504 after one re-read", err, f.rereads.Load()) + } + for _, line := range readLog() { + if strings.Contains(line, marker) && strings.Contains(line, `"status"=503 `) { + return + } + } + t.Fatalf("the coder-errors log has no line with the re-read error %q and status 503", marker) +} diff --git a/internal/aggregated/storage/write_outcome_test.go b/internal/aggregated/storage/write_outcome_test.go index 4a9a9ffd..a5cf0a56 100644 --- a/internal/aggregated/storage/write_outcome_test.go +++ b/internal/aggregated/storage/write_outcome_test.go @@ -8,13 +8,16 @@ import ( "net/http" "net/http/httptest" "strings" + "sync" "sync/atomic" "testing" + "github.com/go-logr/logr/funcr" "github.com/google/uuid" apierrors "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apiserver/pkg/registry/rest" + ctrl "sigs.k8s.io/controller-runtime" aggregationv1alpha1 "github.com/coder/coder-k8s/api/aggregation/v1alpha1" "github.com/coder/coder-k8s/internal/aggregated/coder" @@ -113,17 +116,11 @@ func (rt refusingWrites) RoundTrip(r *http.Request) (*http.Response, error) { return http.DefaultTransport.RoundTrip(r) } -func closedAddress(t *testing.T) string { - t.Helper() - listener, err := net.Listen("tcp", "127.0.0.1:0") - if err != nil { - t.Fatal(err) - } - addr := listener.Addr().String() - if err := listener.Close(); err != nil { - t.Fatal(err) - } - return addr +// closedAddress returns an address that refuses connections. Port 1 is outside the ephemeral +// port range, so a server of a parallel test cannot take it, as it can take a port that a test +// closed. +func closedAddress(_ *testing.T) string { + return "127.0.0.1:1" } type writeCase struct { @@ -132,6 +129,8 @@ type writeCase struct { // checksAnswer is true when the storage checks the object in Coder's answer: the created // object, the build of a workspace update or delete, or the template of a metadata update. checksAnswer bool + // postsBuild is true when the write is a workspace build POST. + postsBuild bool // readsBody is false when the SDK ignores the body of a successful answer. readsBody bool run func(t *testing.T, provider coder.ClientProvider) error @@ -194,6 +193,7 @@ func writeCases() []writeCase { name: "workspace update", isWrite: isBuild, checksAnswer: true, + postsBuild: true, readsBody: true, run: func(t *testing.T, provider coder.ClientProvider) error { workspaces := NewWorkspaceStorage(provider) @@ -211,6 +211,7 @@ func writeCases() []writeCase { name: "workspace delete", isWrite: isBuild, checksAnswer: true, + postsBuild: true, readsBody: true, run: func(_ *testing.T, provider coder.ClientProvider) error { _, _, err := NewWorkspaceStorage(provider).Delete(ctx(), "acme.alice.dev-workspace", nil, nil) @@ -291,6 +292,7 @@ func TestWriteOutcomes(t *testing.T) { always := func(writeCase) bool { return true } readsBody := func(w writeCase) bool { return w.readsBody } checksAnswer := func(w writeCase) bool { return w.checksAnswer } + postsBuild := func(w writeCase) bool { return w.postsBuild } outcomes := []outcome{ {"proxy 502", gatewayPage(http.StatusBadGateway), always}, {"proxy 503", gatewayPage(http.StatusServiceUnavailable), always}, @@ -300,6 +302,15 @@ func TestWriteOutcomes(t *testing.T) { {"201 with an empty object", jsonAnswer(http.StatusCreated, `{}`), checksAnswer}, {"201 with null", jsonAnswer(http.StatusCreated, `null`), checksAnswer}, {"answer without the ID", answerWithoutID, checksAnswer}, + {"proxy 307 without Location", gatewayPage(http.StatusTemporaryRedirect), always}, + {"proxy 400 page", gatewayPage(http.StatusBadRequest), always}, + {"proxy 500 page", gatewayPage(http.StatusInternalServerError), always}, + {"409 with an empty JSON object", jsonAnswer(http.StatusConflict, `{}`), always}, + {"500 with an empty body", jsonAnswer(http.StatusInternalServerError, ``), always}, + {"201 with an empty body", jsonAnswer(http.StatusCreated, ``), readsBody}, + {"201 with a JSON array", jsonAnswer(http.StatusCreated, `[]`), readsBody}, + {"201 with malformed JSON", jsonAnswer(http.StatusCreated, `{"id":`), readsBody}, + {"201 with only a build ID", jsonAnswer(http.StatusCreated, fmt.Sprintf(`{"id":%q}`, uuid.NewString())), postsBuild}, } for _, write := range writeCases() { @@ -356,16 +367,27 @@ func TestTemplateFilesUpdateReReadAfterActivation(t *testing.T) { } jsonAnswer(coderAnswer.Code, string(body))(t, w, coderAnswer) } + coderMessage := uuid.NewString() for _, tc := range []struct { name string answer brokenAnswer // refused sends the re-read to a closed port instead of answer. refused bool + // logsStatus is the status that the coder-errors log must keep with the re-read error, + // or -1 when the test does not check the log. + logsStatus int }{ - {name: "proxy 502", answer: gatewayPage(http.StatusBadGateway)}, - {name: "connection closed without an answer", answer: closedWithoutAnswer}, - {name: "another active version", answer: otherActiveVersion}, - {name: "connection refused", refused: true}, + {name: "proxy 502", answer: gatewayPage(http.StatusBadGateway), logsStatus: -1}, + { + name: "Coder 503", + answer: func(_ *testing.T, w http.ResponseWriter, _ *httptest.ResponseRecorder) { + writeCoderError(w, http.StatusServiceUnavailable, coderMessage) + }, + logsStatus: http.StatusServiceUnavailable, + }, + {name: "connection closed without an answer", answer: closedWithoutAnswer, logsStatus: -1}, + {name: "another active version", answer: otherActiveVersion, logsStatus: -1}, + {name: "connection refused", refused: true, logsStatus: 0}, } { t.Run(tc.name, func(t *testing.T) { t.Parallel() @@ -382,11 +404,15 @@ func TestTemplateFilesUpdateReReadAfterActivation(t *testing.T) { reRead.CompareAndSwap(false, true) } provider := newTestClientProvider(t, writeOutcomeServer(t, coderServer, isReRead, tc.answer).URL) + // logMarker is a unique part of the re-read error. + logMarker := coderMessage if tc.refused { + logMarker = coderServer.URL + "/api/v2/templates/" client := newTestSDKClient(t, coderServer.URL) client.HTTPClient = &http.Client{Transport: refusingWrites{isWrite: isReRead, closedAddr: closedAddress(t)}} provider = &coder.StaticClientProvider{Client: client, Namespace: "control-plane"} } + readLog := captureCoderErrorLog() err := updateTemplateFiles(t, provider) if !reRead.Load() { @@ -395,10 +421,260 @@ func TestTemplateFilesUpdateReReadAfterActivation(t *testing.T) { if !apierrors.IsTimeout(err) || !strings.Contains(err.Error(), "uncertain") { t.Fatalf("expected the uncertain 504, got %v", err) } + if tc.logsStatus < 0 { + return + } + wantStatus := fmt.Sprintf(`"status"=%d `, tc.logsStatus) + for _, line := range readLog() { + if strings.Contains(line, logMarker) && strings.Contains(line, wantStatus) { + return + } + } + t.Fatalf("the coder-errors log has no line with %q and %s", logMarker, wantStatus) + }) + } +} + +var ( + coderErrorLogOnce sync.Once + coderErrorLogMu sync.Mutex + coderErrorLogLines []string +) + +// captureCoderErrorLog routes the controller-runtime logger to memory, once for the test binary, +// and returns a function that reads the coder-errors lines. Tests of this package share the log, +// so a test looks for a part of its own error. +func captureCoderErrorLog() func() []string { + coderErrorLogOnce.Do(func() { + ctrl.SetLogger(funcr.New(func(prefix, args string) { + if prefix != "coder-errors" { + return + } + coderErrorLogMu.Lock() + defer coderErrorLogMu.Unlock() + coderErrorLogLines = append(coderErrorLogLines, args) + }, funcr.Options{Verbosity: 1})) + }) + return func() []string { + coderErrorLogMu.Lock() + defer coderErrorLogMu.Unlock() + return append([]string(nil), coderErrorLogLines...) + } +} + +// TestWorkspaceCreateStoppedStopBuildAnswer checks a create with spec.running=false whose stop +// build POST gets an error or an answer without the requested build, and whose re-read works. A +// re-read that shows the stop build confirms it. After a stop that can have reached Coder, a re-read +// that still shows the start build does not: Coder can still be queueing the stop, so the create +// returns the uncertain 504. After a stop that Coder refused, the start build is the result. +func TestWorkspaceCreateStoppedStopBuildAnswer(t *testing.T) { + t.Parallel() + + for _, tc := range []struct { + name string + answer brokenAnswer + forwarded bool + wantUncertain bool + }{ + {"201 with an empty object", jsonAnswer(http.StatusCreated, `{}`), true, false}, + {"201 with null", jsonAnswer(http.StatusCreated, `null`), true, false}, + {"201 with only a build ID", jsonAnswer(http.StatusCreated, fmt.Sprintf(`{"id":%q}`, uuid.NewString())), true, false}, + {"proxy 502", gatewayPage(http.StatusBadGateway), true, false}, + {"201 with an empty object for a stop that Coder has not queued yet", jsonAnswer(http.StatusCreated, `{}`), false, true}, + {"proxy 502 for a stop that Coder has not queued yet", gatewayPage(http.StatusBadGateway), false, true}, + {"proxy 504 for a stop that Coder has not queued yet", gatewayPage(http.StatusGatewayTimeout), false, true}, + {"Coder 400 for the stop", jsonAnswer(http.StatusBadRequest, `{"message":"bad stop"}`), false, false}, + } { + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + coderServer, _ := newMockCoderServer(t) + t.Cleanup(coderServer.Close) + proxy := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + if r.Method != http.MethodPost || !strings.HasSuffix(r.URL.Path, "/builds") { + coderServer.Config.Handler.ServeHTTP(w, r) + return + } + if tc.forwarded { + recorder := httptest.NewRecorder() + coderServer.Config.Handler.ServeHTTP(recorder, r) + if recorder.Code != http.StatusCreated { + t.Errorf("mock Coder answered the stop with %d: %s", recorder.Code, recorder.Body.String()) + } + } + tc.answer(t, w, nil) + })) + t.Cleanup(proxy.Close) + + ctx := namespacedContext("control-plane") + createdObj, err := NewWorkspaceStorage(newTestClientProvider(t, proxy.URL)).Create(ctx, &aggregationv1alpha1.CoderWorkspace{ + ObjectMeta: metav1.ObjectMeta{Name: "acme.alice.stopped"}, + Spec: aggregationv1alpha1.CoderWorkspaceSpec{Organization: "acme", TemplateName: "starter-template", Running: false}, + }, rest.ValidateAllObjectFunc, nil) + coderObj, getErr := NewWorkspaceStorage(newTestClientProvider(t, coderServer.URL)).Get(ctx, "acme.alice.stopped", nil) + if getErr != nil { + t.Fatalf("get from Coder: %v", getErr) + } + inCoder := coderObj.(*aggregationv1alpha1.CoderWorkspace) + if inCoder.Spec.Running == tc.forwarded { + t.Fatalf("Coder has running=%t, want %t", inCoder.Spec.Running, !tc.forwarded) + } + if tc.wantUncertain { + if !apierrors.IsTimeout(err) || !strings.Contains(err.Error(), "uncertain") || !strings.Contains(err.Error(), "stop") || createdObj != nil { + t.Fatalf("expected the uncertain 504 about the stop and no object, got %v (object returned: %t)", err, createdObj != nil) + } + return + } + if err != nil { + t.Fatalf("create: %v", err) + } + created := createdObj.(*aggregationv1alpha1.CoderWorkspace) + if created.Status.LatestBuildID != inCoder.Status.LatestBuildID || created.Spec.Running != inCoder.Spec.Running { + t.Fatalf("created object has build %s running=%t, Coder has build %s running=%t", + created.Status.LatestBuildID, created.Spec.Running, inCoder.Status.LatestBuildID, inCoder.Spec.Running) + } + }) + } +} + +// latestBuildOnlyID sends Coder's workspace with a latest build that has only its ID. +func latestBuildOnlyID(t *testing.T, w http.ResponseWriter, coderAnswer *httptest.ResponseRecorder) { + var object map[string]any + if err := json.Unmarshal(coderAnswer.Body.Bytes(), &object); err != nil { + t.Fatalf("decode Coder answer: %v", err) + } + object["latest_build"] = map[string]any{"id": uuid.NewString()} + body, err := json.Marshal(object) + if err != nil { + t.Fatal(err) + } + jsonAnswer(coderAnswer.Code, string(body))(t, w, coderAnswer) +} + +// TestWorkspaceCreateStoppedFailedReRead checks a create with spec.running=false whose stop build +// is not confirmed and whose re-read of the workspace fails or has no usable latest build. A stop +// that can have reached Coder returns the uncertain 504 and no object, never the start build as a +// success. A stop that Coder refused leaves the start build, so the create succeeds with it. +func TestWorkspaceCreateStoppedFailedReRead(t *testing.T) { + t.Parallel() + + for _, tc := range []struct { + name string + stopAnswer brokenAnswer + forwarded bool + reRead brokenAnswer + wantUncertain bool + }{ + {"201 with an empty object, re-read 502", jsonAnswer(http.StatusCreated, `{}`), true, gatewayPage(http.StatusBadGateway), true}, + {"201 with an empty object, re-read 404", jsonAnswer(http.StatusCreated, `{}`), true, jsonAnswer(http.StatusNotFound, `{"message":"not found"}`), true}, + {"201 with an empty object, re-read with only a build ID", jsonAnswer(http.StatusCreated, `{}`), true, latestBuildOnlyID, true}, + {"proxy 502, re-read 502", gatewayPage(http.StatusBadGateway), true, gatewayPage(http.StatusBadGateway), true}, + {"proxy 502, re-read 404", gatewayPage(http.StatusBadGateway), true, jsonAnswer(http.StatusNotFound, `{"message":"not found"}`), true}, + {"proxy 400 page, re-read 502", gatewayPage(http.StatusBadRequest), true, gatewayPage(http.StatusBadGateway), true}, + {"proxy 400 page, re-read 404", gatewayPage(http.StatusBadRequest), true, jsonAnswer(http.StatusNotFound, `{"message":"not found"}`), true}, + {"proxy 500 page, re-read 502", gatewayPage(http.StatusInternalServerError), true, gatewayPage(http.StatusBadGateway), true}, + {"proxy 500 page, re-read 404", gatewayPage(http.StatusInternalServerError), true, jsonAnswer(http.StatusNotFound, `{"message":"not found"}`), true}, + {"Coder 400 without the stop, re-read 502", jsonAnswer(http.StatusBadRequest, `{"message":"bad stop"}`), false, gatewayPage(http.StatusBadGateway), false}, + } { + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + coderServer, _ := newMockCoderServer(t) + t.Cleanup(coderServer.Close) + var stops, reReads atomic.Int32 + proxy := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + if r.Method == http.MethodPost && strings.HasSuffix(r.URL.Path, "/builds") { + stops.Add(1) + recorder := httptest.NewRecorder() + if tc.forwarded { + coderServer.Config.Handler.ServeHTTP(recorder, r) + if recorder.Code != http.StatusCreated { + t.Errorf("mock Coder answered the stop with %d: %s", recorder.Code, recorder.Body.String()) + } + } + tc.stopAnswer(t, w, recorder) + return + } + if stops.Load() > 0 && r.Method == http.MethodGet && strings.HasPrefix(r.URL.Path, "/api/v2/workspaces/") { + reReads.Add(1) + recorder := httptest.NewRecorder() + coderServer.Config.Handler.ServeHTTP(recorder, r) + tc.reRead(t, w, recorder) + return + } + coderServer.Config.Handler.ServeHTTP(w, r) + })) + t.Cleanup(proxy.Close) + + ctx := namespacedContext("control-plane") + createdObj, err := NewWorkspaceStorage(newTestClientProvider(t, proxy.URL)).Create(ctx, &aggregationv1alpha1.CoderWorkspace{ + ObjectMeta: metav1.ObjectMeta{Name: "acme.alice.stopped"}, + Spec: aggregationv1alpha1.CoderWorkspaceSpec{Organization: "acme", TemplateName: "starter-template", Running: false}, + }, rest.ValidateAllObjectFunc, nil) + if stops.Load() != 1 || reReads.Load() != 1 { + t.Fatalf("stop POSTs=%d re-reads=%d, want 1 and 1", stops.Load(), reReads.Load()) + } + coderObj, getErr := NewWorkspaceStorage(newTestClientProvider(t, coderServer.URL)).Get(ctx, "acme.alice.stopped", nil) + if getErr != nil { + t.Fatalf("get from Coder: %v", getErr) + } + inCoder := coderObj.(*aggregationv1alpha1.CoderWorkspace) + if inCoder.Spec.Running == tc.forwarded { + t.Fatalf("Coder has running=%t, want %t", inCoder.Spec.Running, !tc.forwarded) + } + + if tc.wantUncertain { + if !apierrors.IsTimeout(err) || !strings.Contains(err.Error(), "uncertain") || !strings.Contains(err.Error(), "stop") || createdObj != nil { + t.Fatalf("expected the uncertain 504 about the stop and no object, got %v (object returned: %t)", err, createdObj != nil) + } + return + } + if err != nil { + t.Fatalf("create: %v", err) + } + if created := createdObj.(*aggregationv1alpha1.CoderWorkspace); created.Status.LatestBuildID != inCoder.Status.LatestBuildID || !created.Spec.Running { + t.Fatalf("created object has build %s running=%t, Coder has the start build %s", created.Status.LatestBuildID, created.Spec.Running, inCoder.Status.LatestBuildID) + } }) } } +// TestWorkspaceCreateStoppedStopNotSent: the stop build POST of a create with spec.running=false +// is refused before it is sent, and so is the re-read. The stop did not reach Coder, so the create +// succeeds with the start build. +func TestWorkspaceCreateStoppedStopNotSent(t *testing.T) { + t.Parallel() + + coderServer, _ := newMockCoderServer(t) + t.Cleanup(coderServer.Close) + var stopTried atomic.Bool + refused := func(r *http.Request) bool { + if r.Method == http.MethodPost && strings.HasSuffix(r.URL.Path, "/builds") { + stopTried.Store(true) + return true + } + return stopTried.Load() && r.Method == http.MethodGet && strings.HasPrefix(r.URL.Path, "/api/v2/workspaces/") + } + client := newTestSDKClient(t, coderServer.URL) + client.HTTPClient = &http.Client{Transport: refusingWrites{isWrite: refused, closedAddr: closedAddress(t)}} + + ctx := namespacedContext("control-plane") + createdObj, err := NewWorkspaceStorage(&coder.StaticClientProvider{Client: client, Namespace: "control-plane"}).Create(ctx, &aggregationv1alpha1.CoderWorkspace{ + ObjectMeta: metav1.ObjectMeta{Name: "acme.alice.stopped"}, + Spec: aggregationv1alpha1.CoderWorkspaceSpec{Organization: "acme", TemplateName: "starter-template", Running: false}, + }, rest.ValidateAllObjectFunc, nil) + if err != nil || !stopTried.Load() { + t.Fatalf("create: err=%v, stop tried=%t; want success after a stop attempt", err, stopTried.Load()) + } + coderObj, err := NewWorkspaceStorage(newTestClientProvider(t, coderServer.URL)).Get(ctx, "acme.alice.stopped", nil) + if err != nil { + t.Fatalf("get from Coder: %v", err) + } + created, inCoder := createdObj.(*aggregationv1alpha1.CoderWorkspace), coderObj.(*aggregationv1alpha1.CoderWorkspace) + if !inCoder.Spec.Running || !created.Spec.Running || created.Status.LatestBuildID != inCoder.Status.LatestBuildID { + t.Fatalf("created object has build %s running=%t, Coder has the start build %s running=%t", + created.Status.LatestBuildID, created.Spec.Running, inCoder.Status.LatestBuildID, inCoder.Spec.Running) + } +} + // TestTemplateUpdateReadAfterChange checks the read of the template that ends an update. When it // fails after Coder applied the change, the update returns the uncertain 504. func TestTemplateUpdateReadAfterChange(t *testing.T) {