diff --git a/docs/how-to/troubleshooting.md b/docs/how-to/troubleshooting.md index 3cfb0d52..8751690d 100644 --- a/docs/how-to/troubleshooting.md +++ b/docs/how-to/troubleshooting.md @@ -365,7 +365,7 @@ The pool checks its inputs in Coder, and each member checks them again right bef | `DeadlineExceeded` | failure | The workspace was not ready within `spec.readyTimeoutSeconds` (default 900) of the member's creation. The message names the last wait. | Fix the cause of the last wait, or raise `readyTimeoutSeconds`. | | `WorkspaceReady` | ready | Every agent is ready. A claim can take the workspace. | None. | | `Used` | wait | The workspace's `last_used_at` moved after it became ready, so someone used it without a claim, or Coder counted something else as a use. Opening the workspace's page in the Coder dashboard counts ([#444](https://github.com/coder/coder-k8s/issues/444)). The member gets `Used=True`, and the pool releases it. | See [Cleanup](workspace-pools.md#cleanup). | -| `AgentNotReady` | wait | An agent of a ready workspace disconnected or is no longer ready. No claim takes the workspace meanwhile. | None, unless it becomes `AgentLost`. | +| `AgentNotReady` | wait | An agent of a ready workspace disconnected or is no longer ready. No claim takes the workspace meanwhile. A failed Coder read keeps this reason, and the 5 min keep counting. | None, unless it becomes `AgentLost`. | | `AgentLost` | failure | An agent stayed not ready for 5 min. | Read the agent logs in Coder. | | `ChangedExternally` | failure | Someone else started a build of the workspace, for example a stop, an update, or Coder's autostop. | None. The pool replaces an unclaimed member. | | `Dormant` | failure | Coder marked the workspace dormant, or scheduled its deletion. | Check the template's dormancy settings. | diff --git a/internal/controller/coderworkspacepoolmember_extend.go b/internal/controller/coderworkspacepoolmember_extend.go index dbd05c31..a1a20d0e 100644 --- a/internal/controller/coderworkspacepoolmember_extend.go +++ b/internal/controller/coderworkspacepoolmember_extend.go @@ -84,9 +84,11 @@ func (r *CoderWorkspacePoolMemberReconciler) keepWarm( return coderWait("MaxDeadline", "Coder stops workspace %s at its max deadline %s, which allows no extension.", name, build.MaxDeadline.Time.UTC().Format(time.RFC3339)), nil } - if bound && target == nil { + if bound && (target == nil || target.After(to)) { // Store the target before the request: a later read then proves // whether the extension happened, whatever status write is lost. + // A stored target later than a fresh extension counts as missing, + // so a status writer cannot choose the deadline (plan section 16). member.Status.BindExtendDeadline = &metav1.Time{Time: to} if err := r.writeStatus(ctx, member, before); err != nil { return nil, err diff --git a/internal/controller/coderworkspacepoolmember_extend_test.go b/internal/controller/coderworkspacepoolmember_extend_test.go index 90f6d6d6..40a52c6f 100644 --- a/internal/controller/coderworkspacepoolmember_extend_test.go +++ b/internal/controller/coderworkspacepoolmember_extend_test.go @@ -326,6 +326,44 @@ func TestPoolMemberBindExtensionConfirmed(t *testing.T) { require.Equal(t, requests, e.fake.requestCount(routeExtendWorkspace)) } +// TestPoolMemberBoundsStoredExtendTimes: a status writer chooses no deadline +// (plan section 16). A stored bind target later than a fresh extension counts +// as missing, and a future lastExtendTime stops no extension. +func TestPoolMemberBoundsStoredExtendTimes(t *testing.T) { + t.Parallel() + e := newPoolMemberEnv(t) + e.fake.setTemplateSchedule(e.tplID, time.Hour, 0) + started := e.clock.Now() + future := metav1.NewTime(started.Add(365 * 24 * time.Hour)) + + key, workspaceID := e.readyMember(t) + e.clock.SetTime(started.Add(10 * time.Minute)) + member := e.reconcileMember(t, key, 0) + member.Spec.ClaimRef = &coderv1alpha1.CoderWorkspaceClaimReference{Name: "build-1", UID: uuid.NewString()} + require.NoError(t, k8sClient.Update(e.ctx, member)) + member.Status.BindExtendDeadline = &future + require.NoError(t, k8sClient.Status().Update(e.ctx, member)) + member = e.reconcileMember(t, key, 1) + requireMember(t, member, coderv1alpha1.CoderWorkspacePoolMemberPhaseReady, "Bound", "bound to claim build-1") + want := e.clock.Now().Add(time.Hour) + require.True(t, e.deadline(t, workspaceID).Time.Equal(want), "Coder deadline %s, want now + TTL", e.deadline(t, workspaceID).Time) + require.True(t, member.Status.BindExtendDeadline.Time.Equal(want), "the member stores the target it asks for") + require.True(t, member.Status.BindExtended) + + e.clock.SetTime(started) + key, workspaceID = e.readyMember(t) + member = e.reconcileMember(t, key, 0) + member.Status.LastExtendTime = &future + require.NoError(t, k8sClient.Status().Update(e.ctx, member)) + extends := e.fake.requestCount(routeExtendWorkspace) + e.clock.SetTime(started.Add(46 * time.Minute)) + member = e.reconcileMember(t, key, 1) + requireReady(t, member, "extended the deadline") + require.Equal(t, extends+1, e.fake.requestCount(routeExtendWorkspace)) + require.True(t, member.Status.LastExtendTime.Time.Equal(e.clock.Now())) + require.True(t, e.deadline(t, workspaceID).Time.Equal(e.clock.Now().Add(time.Hour))) +} + // TestPoolMemberGuardsEveryExtension: the read right before an extension // proves that the workspace is the member's own and still runs its start // build. Otherwise the member never writes to it. diff --git a/internal/controller/coderworkspacepoolmember_ready.go b/internal/controller/coderworkspacepoolmember_ready.go index e489bd1d..be98a503 100644 --- a/internal/controller/coderworkspacepoolmember_ready.go +++ b/internal/controller/coderworkspacepoolmember_ready.go @@ -28,7 +28,7 @@ func (r *CoderWorkspacePoolMemberReconciler) readWorkspace( sdk, _, wait, err := controlPlaneCoderClient(ctx, r.Client, member.Namespace, member.Spec.ControlPlaneRef.Name) switch { case wait != nil: - return coderWait(wait.reason, "%s", wait.message), nil + return poolMemberKeepAgentNotReady(member, coderWait(wait.reason, "%s", wait.message)), nil case err != nil: return nil, err case member.Status.WorkspaceID == "": diff --git a/internal/controller/coderworkspacepoolmember_watch.go b/internal/controller/coderworkspacepoolmember_watch.go index 4284e0fb..80c9b342 100644 --- a/internal/controller/coderworkspacepoolmember_watch.go +++ b/internal/controller/coderworkspacepoolmember_watch.go @@ -35,8 +35,8 @@ func (r *CoderWorkspacePoolMemberReconciler) watchReady( // answers 410 once someone deleted the workspace, which sets // WorkspaceDeleted=True, and the claim becomes Lost. workspace, operatorID, step, err := readPoolMemberWorkspace(ctx, sdk, member) - if step != nil || err != nil { - return step, err + if step, err = memberWaitOnWrongAnswer(ctx, step, err); step != nil || err != nil { + return poolMemberKeepAgentNotReady(member, step), err } if bound && member.Status.BindExtended { // The one extension at bind is done. Builds by the claimant, a stop @@ -114,3 +114,19 @@ func poolMemberAgentStep(member *coderv1alpha1.CoderWorkspacePoolMember, build c } return coderWait("AgentNotReady", "%s", step.message) } + +// poolMemberKeepAgentNotReady keeps watch rule 3 across a step that read no +// agent, such as a failed Coder read (plan section 16): a member whose agent +// was not ready stays not ready, so its 5 minutes keep counting from the read +// that found the agent not ready. +func poolMemberKeepAgentNotReady(member *coderv1alpha1.CoderWorkspacePoolMember, step *coderStep) *coderStep { + c := meta.FindStatusCondition(member.Status.Conditions, coderv1alpha1.CoderWorkspacePoolMemberConditionReady) + if step == nil || step.failed || member.Status.ReadyTime == nil || c == nil || + c.Status != metav1.ConditionFalse || c.Reason != "AgentNotReady" { + return step + } + kept := *step + kept.reason = "AgentNotReady" + kept.message = step.message + " The agent was not ready at the last read, so the member stays not ready." + return &kept +} diff --git a/internal/controller/coderworkspacepoolmember_watch_test.go b/internal/controller/coderworkspacepoolmember_watch_test.go index ed1eb2cb..43b069e6 100644 --- a/internal/controller/coderworkspacepoolmember_watch_test.go +++ b/internal/controller/coderworkspacepoolmember_watch_test.go @@ -151,6 +151,37 @@ func TestPoolMemberWatchRules(t *testing.T) { // The 5 minutes count from the first read that found the agent lost. e.fake.setAgents(buildID, lost) requireNotReady(t, 4*time.Minute) + // A read that proves nothing keeps the member not ready, and the 5 + // minutes run on (plan section 16). + setOperatorAccess := func(t *testing.T, ready bool) { + t.Helper() + cp := &coderv1alpha1.CoderControlPlane{} + require.NoError(t, k8sClient.Get(e.ctx, types.NamespacedName{Namespace: e.ns, Name: "coder"}, cp)) + cp.Status.OperatorAccessReady = ready + require.NoError(t, k8sClient.Status().Update(e.ctx, cp)) + } + for i, c := range []struct { + fail func(t *testing.T) + message string + }{ + {func(*testing.T) { e.fake.failNext(routeWorkspace, fakeFault{Status: 503}) }, "Coder answered 503"}, + {func(*testing.T) { + e.fake.failNext(routeWorkspace, fakeFault{Rewrite: func(answer any) any { + ws := answer.(codersdk.Workspace) + ws.ID = uuid.New() + return ws + }}) + }, "Coder answered workspace"}, + {func(t *testing.T) { setOperatorAccess(t, false) }, "no operator access"}, + } { + e.clock.SetTime(started.Add(5*time.Minute + time.Duration(i)*time.Minute)) + c.fail(t) + member := e.reconcileMember(t, key, 1) + requireMember(t, member, coderv1alpha1.CoderWorkspacePoolMemberPhaseReady, "AgentNotReady", c.message) + ready := meta.FindStatusCondition(member.Status.Conditions, coderv1alpha1.CoderWorkspacePoolMemberConditionReady) + require.True(t, ready.LastTransitionTime.Time.Equal(started.Add(4*time.Minute)), "the agent is not ready since %s", ready.LastTransitionTime) + } + setOperatorAccess(t, true) requireNotReady(t, 9*time.Minute-time.Second) e.clock.SetTime(started.Add(9 * time.Minute)) requireMemberFailed(t, e.reconcileMember(t, key, 1), "AgentLost", "has not been ready since", metav1.ConditionFalse)