diff --git a/pkg/controllers/agentsession/bundle_midsession_unready_message_test.go b/pkg/controllers/agentsession/bundle_midsession_unready_message_test.go new file mode 100644 index 0000000..70d2360 --- /dev/null +++ b/pkg/controllers/agentsession/bundle_midsession_unready_message_test.go @@ -0,0 +1,174 @@ +// pkg/controllers/agentsession/bundle_midsession_unready_message_test.go +// +// A bundle that became Ready and later turned unhealthy mid-session (an +// OOM-killed container, an evicted pod) lands in the same not-ready deadline +// backstop as a bundle that never booted — the deadline is measured from the +// bundle's CreationTimestamp, so mid-session it is trivially exceeded on the +// first not-ready pass. The terminal message must not describe that as a +// provisioning failure ("did not become Ready within 8m0s of provisioning +// start … likely a slow/cold image pull"): in a real incident the images were +// cached, the bundle was Ready in 13 seconds, and the wording sent the +// operator chasing an image pull for what was a cgroup OOM kill 35 minutes +// into the session. The session's own BundlesReady=True condition is the +// durable record that boot succeeded; when it is set, the message must say the +// bundle became unhealthy after running, not that it never started. +package agentsession_test + +import ( + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + corev1 "k8s.io/api/core/v1" + apimeta "k8s.io/apimachinery/pkg/api/meta" + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + + spiceboxv1alpha1 "github.com/authzed/openagentprimitives/pkg/apis/v1alpha1" +) + +// runningNotReadyPod is a scheduled, Running pod whose Ready condition is +// False — the state kubelet reports while a killed container restarts. Any +// container statuses given are attached verbatim. +func runningNotReadyPod(name string, created time.Time, cs ...corev1.ContainerStatus) *corev1.Pod { + return &corev1.Pod{ + ObjectMeta: metav1.ObjectMeta{ + Name: name, Namespace: "default", + CreationTimestamp: metav1.NewTime(created), + }, + Status: corev1.PodStatus{ + Phase: corev1.PodRunning, + Conditions: []corev1.PodCondition{ + {Type: corev1.PodScheduled, Status: corev1.ConditionTrue}, + {Type: corev1.PodReady, Status: corev1.ConditionFalse}, + }, + ContainerStatuses: cs, + }, + } +} + +// midSessionUnreadyFixture builds the incident shape: a 35m-old session whose +// bundles all became Ready 34m ago (the durable BundlesReady condition), with +// the bundle now not-Ready and its pod Running but unready. +func midSessionUnreadyFixture(nowT time.Time, pod *corev1.Pod) (*spiceboxv1alpha1.AgentClass, *spiceboxv1alpha1.AgentSession, *spiceboxv1alpha1.SpiceboxSession) { + started := nowT.Add(-35 * time.Minute) + ac := classWithBundle("ac1", spiceboxv1alpha1.ToolBundle{Name: "code", Class: "toolbelt"}) + sess := sessionCreatedAt("s1", "ac1", started) + sess.Status.Conditions = []metav1.Condition{{ + Type: spiceboxv1alpha1.AgentSessionConditionBundlesReady, Status: metav1.ConditionTrue, + Reason: "AllBundlesReady", + LastTransitionTime: metav1.NewTime(nowT.Add(-34 * time.Minute)), + }} + bundle := bundleWithPod("s1", "code", pod.Name, started) + return ac, sess, bundle +} + +func TestReconcileBundleTimeout_MidSessionUnreadyIsNotBlamedOnProvisioning(t *testing.T) { + nowT := time.Date(2026, 6, 28, 12, 0, 0, 0, time.UTC) + clock := func() time.Time { return nowT } + + pod := runningNotReadyPod("s1-code-pod", nowT.Add(-35*time.Minute)) + ac, sess, bundle := midSessionUnreadyFixture(nowT, pod) + + r, c := fakeReconciler(t, clock, ac, sess, bundle, pod) + runReconciles(t, r, "s1", 5) + + got := getSession(t, c, "s1") + require.Equal(t, spiceboxv1alpha1.AgentSessionPhaseFailed, got.Status.Phase, + "a mid-session bundle death still fails the session (recovery semantics are separate)") + // The Reason token must stay the exact "BundleFailed" constant — it is the + // lookup key lifecycle's transientBootFailures uses to classify a follow-up + // message as recoverable. + assert.Equal(t, spiceboxv1alpha1.ReasonAgentSessionBundleFail, got.Status.FailureReason) + + fc := apimeta.FindStatusCondition(got.Status.Conditions, spiceboxv1alpha1.AgentSessionConditionFailed) + require.NotNil(t, fc, "Failed condition set") + assert.Contains(t, fc.Message, "became unhealthy", + "message says the bundle died after running, not that it never started") + assert.Contains(t, fc.Message, "s1-code", "message names the offending bundle") + assert.Contains(t, fc.Message, "kubectl -n default describe pod s1-code-pod", + "message keeps the actionable kubectl pointer") + assert.NotContains(t, fc.Message, "image pull", + "a bundle that was Ready for half an hour must not be blamed on an image pull") + assert.NotContains(t, fc.Message, "did not become Ready within", + "must not use boot-deadline framing for a mid-session death") +} + +// When kubelet has already recorded WHY the container died — the +// LastTerminationState of a restarting container, e.g. OOMKilled/137 — the +// message must name that observed cause instead of listing guesses. +func TestReconcileBundleTimeout_MidSessionUnreadyNamesContainerTermination(t *testing.T) { + nowT := time.Date(2026, 6, 28, 12, 0, 0, 0, time.UTC) + clock := func() time.Time { return nowT } + + pod := runningNotReadyPod("s1-code-pod", nowT.Add(-35*time.Minute), + // A successfully-Completed container (exit 0) must not be mistaken + // for the failure. + corev1.ContainerStatus{ + Name: "setup", + State: corev1.ContainerState{Terminated: &corev1.ContainerStateTerminated{ + Reason: "Completed", ExitCode: 0, + }}, + }, + corev1.ContainerStatus{ + Name: "sandbox", + RestartCount: 1, + State: corev1.ContainerState{Waiting: &corev1.ContainerStateWaiting{Reason: "CrashLoopBackOff"}}, + LastTerminationState: corev1.ContainerState{Terminated: &corev1.ContainerStateTerminated{ + Reason: "OOMKilled", ExitCode: 137, + }}, + }) + ac, sess, bundle := midSessionUnreadyFixture(nowT, pod) + + r, c := fakeReconciler(t, clock, ac, sess, bundle, pod) + runReconciles(t, r, "s1", 5) + + got := getSession(t, c, "s1") + require.Equal(t, spiceboxv1alpha1.AgentSessionPhaseFailed, got.Status.Phase) + fc := apimeta.FindStatusCondition(got.Status.Conditions, spiceboxv1alpha1.AgentSessionConditionFailed) + require.NotNil(t, fc, "Failed condition set") + assert.Contains(t, fc.Message, "OOMKilled", + "message names the container's actual recorded termination reason") + assert.Contains(t, fc.Message, `container "sandbox"`, + "message names which container died, not the Completed one") + assert.Contains(t, fc.Message, "exit code 137") + assert.NotContains(t, fc.Message, "likely", + "an observed termination replaces the guess list") +} + +// The boot path gets the same honesty: a bundle that NEVER became Ready keeps +// the provisioning-deadline framing, but when its container is crash-looping +// with a recorded termination, the message names that exit instead of blaming +// a slow image pull. +func TestReconcileBundleTimeout_BootCrashLoopNamesContainerTermination(t *testing.T) { + nowT := time.Date(2026, 6, 28, 12, 0, 0, 0, time.UTC) + clock := func() time.Time { return nowT } + started := nowT.Add(-10 * time.Minute) + + ac := classWithBundle("ac1", spiceboxv1alpha1.ToolBundle{Name: "code", Class: "toolbelt"}) + sess := sessionCreatedAt("s1", "ac1", started) // no BundlesReady=True: never booted + bundle := bundleWithPod("s1", "code", "s1-code-pod", started) + pod := runningNotReadyPod("s1-code-pod", started, corev1.ContainerStatus{ + Name: "sandbox", + RestartCount: 4, + State: corev1.ContainerState{Waiting: &corev1.ContainerStateWaiting{Reason: "CrashLoopBackOff"}}, + LastTerminationState: corev1.ContainerState{Terminated: &corev1.ContainerStateTerminated{ + Reason: "Error", ExitCode: 1, + }}, + }) + + r, c := fakeReconciler(t, clock, ac, sess, bundle, pod) + runReconciles(t, r, "s1", 5) + + got := getSession(t, c, "s1") + require.Equal(t, spiceboxv1alpha1.AgentSessionPhaseFailed, got.Status.Phase) + fc := apimeta.FindStatusCondition(got.Status.Conditions, spiceboxv1alpha1.AgentSessionConditionFailed) + require.NotNil(t, fc, "Failed condition set") + assert.Contains(t, fc.Message, "did not become Ready within", + "a never-Ready bundle keeps the provisioning-deadline framing") + assert.Contains(t, fc.Message, `container "sandbox"`) + assert.Contains(t, fc.Message, "exit code 1", + "message names the recorded crash instead of guessing") + assert.NotContains(t, fc.Message, "image pull", + "an observed crash replaces the image-pull guess") +} diff --git a/pkg/controllers/agentsession/controller.go b/pkg/controllers/agentsession/controller.go index a0d1602..0f577a7 100644 --- a/pkg/controllers/agentsession/controller.go +++ b/pkg/controllers/agentsession/controller.go @@ -376,6 +376,61 @@ func (r *Reconciler) schedulingStallForPod(ctx context.Context, namespace, podNa }, true } +// containerTermination is a container death kubelet has already recorded on a +// bundle pod — the observed cause the terminal Failed message names instead of +// guessing ("likely a slow image pull / OOM kill / …"). +type containerTermination struct { + podName string + container string + reason string // kubelet's Terminated.Reason, e.g. "OOMKilled"; may be "" + exitCode int32 +} + +func (t containerTermination) message() string { + reason := t.reason + if reason == "" { + reason = "Error" + } + return fmt.Sprintf("container %q in pod %q terminated: %s (exit code %d)", t.container, t.podName, reason, t.exitCode) +} + +// firstContainerTermination returns the first failed container termination +// recorded across the named pods: a currently-terminated container, or a +// restarting container's LastTerminationState — which is how an OOM-killed +// container appears while its restart backs off. Exit-code-0 terminations are +// skipped (a Completed init/sidecar container is not the failure). FAIL-SAFE: +// pod misses are skipped; ok=false keeps the caller's generic message. +func (r *Reconciler) firstContainerTermination(ctx context.Context, namespace string, podNames []string) (containerTermination, bool) { + for _, name := range podNames { + if name == "" { + continue + } + var pod corev1.Pod + if err := r.Client.Get(ctx, client.ObjectKey{Namespace: namespace, Name: name}, &pod); err != nil { + continue + } + statuses := make([]corev1.ContainerStatus, 0, len(pod.Status.InitContainerStatuses)+len(pod.Status.ContainerStatuses)) + statuses = append(statuses, pod.Status.InitContainerStatuses...) + statuses = append(statuses, pod.Status.ContainerStatuses...) + for _, cs := range statuses { + term := cs.State.Terminated + if term == nil { + term = cs.LastTerminationState.Terminated + } + if term == nil || term.ExitCode == 0 { + continue + } + return containerTermination{ + podName: pod.Name, + container: cs.Name, + reason: term.Reason, + exitCode: term.ExitCode, + }, true + } + } + return containerTermination{}, false +} + // firstSchedulingStall returns the first pod in podNames stuck Pending on a // scheduling failure. FAIL-SAFE (each pod miss is skipped); ok=false means none // are stalled, so the caller keeps the generic waiting message. @@ -1685,9 +1740,32 @@ func (r *Reconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Resu // likely an image pull" for a taint-blocked pod (as this once did) // sends the user chasing a cause that isn't the problem. var msg string + bundlesWereReady := meta.FindStatusCondition(sess.Status.Conditions, spiceboxv1alpha1.AgentSessionConditionBundlesReady) if stall, ok := r.firstSchedulingStall(ctx, sess.Namespace, notReadyPods); ok { msg = fmt.Sprintf("sandbox bundle(s) %v did not become Ready within %s of provisioning start: %s is unschedulable: %s", notReadyBundles, bundleDeadline, stall.podName, strings.TrimSuffix(stall.reason, ".")) + } else if bundlesWereReady != nil && bundlesWereReady.Status == metav1.ConditionTrue { + // The bundles all became Ready earlier in this session's life — + // the durable BundlesReady condition is the record — so this is + // not a provisioning problem at all: a bundle that was serving + // turned unhealthy mid-session (an OOM-killed or crashed + // container, an evicted pod). The deadline math cannot tell the + // two apart — mid-session, "now − bundle creation" is always + // past the deadline — and blaming a slow image pull here once + // sent an operator chasing image pulls for a cgroup OOM kill. + readySince := bundlesWereReady.LastTransitionTime.UTC().Format(time.RFC3339) + if term, ok := r.firstContainerTermination(ctx, sess.Namespace, notReadyPods); ok { + // kubelet already recorded the death — name it (an OOM + // kill shows as OOMKilled/137) instead of guessing. + msg = fmt.Sprintf("sandbox bundle(s) %v became unhealthy after running (Ready since %s): %s", + notReadyBundles, readySince, term.message()) + } else { + msg = fmt.Sprintf("sandbox bundle(s) %v became unhealthy after running (Ready since %s): a pod stopped being Ready mid-session — likely a crashed or OOM-killed container, or an evicted pod", + notReadyBundles, readySince) + } + } else if term, ok := r.firstContainerTermination(ctx, sess.Namespace, notReadyPods); ok { + msg = fmt.Sprintf("sandbox bundle(s) %v did not become Ready within %s of provisioning start: %s", + notReadyBundles, bundleDeadline, term.message()) } else { msg = fmt.Sprintf("sandbox bundle(s) %v did not become Ready within %s of provisioning start; the pod(s) scheduled but never became Ready, so the likely cause is a slow/cold image pull or a crashing container", notReadyBundles, bundleDeadline)