Ensure terminal pods maintain terminal status #105462

ehashman · 2021-10-04T17:10:36Z

Alternative to #105411. This is a slightly tighter patch and appears to also fix the issue.

What type of PR is this?

/kind bug
/sig node
/priority critical-urgent

What this PR does / why we need it:

Avoids overwriting statuses or phase on terminated pods.

Which issue(s) this PR fixes:

Fixes #105358

Special notes for your reviewer

This avoids an isTerminated check, which we may not need. We can fix the container restart count issue separately.

Does this PR introduce a user-facing change?

Evicted and other terminated pods will no longer revert to Running phase

Additional documentation e.g., KEPs (Kubernetes Enhancement Proposals), usage docs, etc.:

ehashman · 2021-10-04T17:11:54Z

/test pull-kubernetes-node-kubelet-eviction
/test pull-kubernetes-node-kubelet-serial

ehashman · 2021-10-04T18:41:59Z

pkg/kubelet/status/status_manager_test.go

@@ -622,6 +622,64 @@ func TestTerminatePod(t *testing.T) {
 	assert.Equal(t, newStatus.Message, firstStatus.Message)
 }

+func TestTerminatePodWaiting(t *testing.T) {


Basically copied from test above, but changed (init)container 3 to waiting status

pkg/kubelet/kubelet_pods_test.go

rphillips · 2021-10-04T20:43:21Z

/triage accepted

rphillips · 2021-10-04T22:16:30Z

/retest-required

ehashman · 2021-10-05T18:36:30Z

Oct 05 17:41:03 kind-worker kubelet[248]: I1005 17:41:03.668493     248 config.go:383] "Receiving a new pod" pod="pods-7829/pod-submit-status-0-13"
Oct 05 17:41:03 kind-worker kubelet[248]: I1005 17:41:03.669167     248 kubelet.go:2055] "SyncLoop ADD" source="api" pods=[pods-7829/pod-submit-status-0-13]
Oct 05 17:41:03 kind-worker kubelet[248]: I1005 17:41:03.669398     248 pod_workers.go:535] "Pod is being synced for the first time" pod="pods-7829/pod-submit-status-0-13" podUID=a409f0f6-ac57-4d5e-95e1-97e074ea74b7
Oct 05 17:41:03 kind-worker kubelet[248]: I1005 17:41:03.669503     248 pod_workers.go:742] "Processing pod event" pod="pods-7829/pod-submit-status-0-13" podUID=a409f0f6-ac57-4d5e-95e1-97e074ea74b7 updateType=0
Oct 05 17:41:03 kind-worker kubelet[248]: I1005 17:41:03.669541     248 kubelet.go:1533] "syncPod enter" pod="pods-7829/pod-submit-status-0-13" podUID=a409f0f6-ac57-4d5e-95e1-97e074ea74b7
Oct 05 17:41:03 kind-worker kubelet[248]: I1005 17:41:03.669559     248 kubelet_pods.go:1437] "Generating pod status" pod="pods-7829/pod-submit-status-0-13"
Oct 05 17:41:03 kind-worker kubelet[248]: I1005 17:41:03.669600     248 kubelet_pods.go:1449] "Got phase for pod" pod="pods-7829/pod-submit-status-0-13" oldPhase=Pending phase=Pending
Oct 05 17:41:03 kind-worker kubelet[248]: I1005 17:41:03.694537     248 kubelet.go:2071] "SyncLoop DELETE" source="api" pods=[pods-7829/pod-submit-status-0-13]

The node got a DELETE before it even started to spin up the pod... looks like it wasn't able to sync out the final status due to client-side throttling:

Oct 05 17:41:05 kind-worker kubelet[248]: I1005 17:41:05.527801     248 pod_workers.go:931] "Pod is complete and the worker can now stop" pod="pods-7829/pod-submit-status-0-13" podUID=a409f0f6-ac57-4d5e-95e1-97e074ea74b7
Oct 05 17:41:05 kind-worker kubelet[248]: I1005 17:41:05.527832     248 pod_workers.go:811] "Processing pod event done" pod="pods-7829/pod-submit-status-0-13" podUID=a409f0f6-ac57-4d5e-95e1-97e074ea74b7 updateType=2
Oct 05 17:41:09 kind-worker kubelet[248]: I1005 17:41:09.645158     248 request.go:597] Waited for 386.835047ms due to client-side throttling, not priority and fairness, request: GET:https://kind-control-plane:6443/api/v1/namespaces/pods-7829/pods/pod-submit-status-0-13
Oct 05 17:41:09 kind-worker kubelet[248]: I1005 17:41:09.843151     248 request.go:597] Waited for 154.773669ms due to client-side throttling, not priority and fairness, request: PATCH:https://kind-control-plane:6443/api/v1/namespaces/pods-7829/pods/pod-submit-status-0-13/status
Oct 05 17:41:09 kind-worker kubelet[248]: I1005 17:41:09.860368     248 status_manager.go:622] "Patch status for pod" pod="pods-7829/pod-submit-status-0-13" patch="{\"metadata\":{\"uid\":\"a409f0f6-ac57-4d5e-95e1-97e074ea74b7\"},\"status\":{\"$setElementOrder/conditions\":[{\"type\":\"Initialized\"},{\"type\":\"Ready\"},{\"type\":\"ContainersReady\"},{\"type\":\"PodScheduled\"}],\"conditions\":[{\"lastProbeTime\":null,\"lastTransitionTime\":\"2021-10-05T17:41:03Z\",\"status\":\"True\",\"type\":\"Initialized\"},{\"lastProbeTime\":null,\"lastTransitionTime\":\"2021-10-05T17:41:03Z\",\"message\":\"containers with unready status: [busybox]\",\"reason\":\"ContainersNotReady\",\"status\":\"False\",\"type\":\"Ready\"},{\"lastProbeTime\":null,\"lastTransitionTime\":\"2021-10-05T17:41:03Z\",\"message\":\"containers with unready status: [busybox]\",\"reason\":\"ContainersNotReady\",\"status\":\"False\",\"type\":\"ContainersReady\"}],\"containerStatuses\":[{\"image\":\"k8s.gcr.io/e2e-test-images/busybox:1.29-2\",\"imageID\":\"\",\"lastState\":{},\"name\":\"busybox\",\"ready\":false,\"restartCount\":0,\"started\":false,\"state\":{\"terminated\":{\"exitCode\":137,\"finishedAt\":null,\"message\":\"The container could not be located when the pod was terminated\",\"reason\":\"ContainerStatusUnknown\",\"startedAt\":null}}}],\"hostIP\":\"172.18.0.2\",\"podIP\":\"10.244.1.111\",\"podIPs\":[{\"ip\":\"10.244.1.111\"}],\"startTime\":\"2021-10-05T17:41:03Z\"}}"
Oct 05 17:41:09 kind-worker kubelet[248]: I1005 17:41:09.860488     248 status_manager.go:631] "Status for pod updated successfully" pod="pods-7829/pod-submit-status-0-13" statusVersion=4 status={Phase:Pending Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2021-10-05 17:41:03 +0000 UTC Reason: Message:} {Type:Ready Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2021-10-05 17:41:03 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [busybox]} {Type:ContainersReady Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2021-10-05 17:41:03 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [busybox]} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2021-10-05 17:41:03 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:172.18.0.2 PodIP:10.244.1.111 PodIPs:[{IP:10.244.1.111}] StartTime:2021-10-05 17:41:03 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:busybox State:{Waiting:nil Running:nil Terminated:&ContainerStateTerminated{ExitCode:137,Signal:0,Reason:ContainerStatusUnknown,Message:The container could not be located when the pod was terminated,StartedAt:0001-01-01 00:00:00 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,ContainerID:,}} LastTerminationState:{Waiting:nil Running:nil Terminated:nil} Ready:false RestartCount:0 Image:k8s.gcr.io/e2e-test-images/busybox:1.29-2 ImageID: ContainerID: Started:0xc0014d25a8}] QOSClass:Burstable EphemeralContainerStatuses:[]}
Oct 05 17:41:09 kind-worker kubelet[248]: I1005 17:41:09.860884     248 kubelet_pods.go:951] "Pod is terminated and all resources are reclaimed" pod="pods-7829/pod-submit-status-0-13"
Oct 05 17:41:09 kind-worker kubelet[248]: I1005 17:41:09.861840     248 kubelet.go:2068] "SyncLoop RECONCILE" source="api" pods=[pods-7829/pod-submit-status-0-13]
Oct 05 17:41:10 kind-worker kubelet[248]: I1005 17:41:10.042381     248 request.go:597] Waited for 181.389859ms due to client-side throttling, not priority and fairness, request: DELETE:https://kind-control-plane:6443/api/v1/namespaces/pods-7829/pods/pod-submit-status-0-13
Oct 05 17:41:10 kind-worker kubelet[248]: I1005 17:41:10.102100     248 kubelet.go:2071] "SyncLoop DELETE" source="api" pods=[pods-7829/pod-submit-status-0-13]
Oct 05 17:41:10 kind-worker kubelet[248]: I1005 17:41:10.102555     248 pod_workers.go:557] "Pod is finished processing, no further updates" pod="pods-7829/pod-submit-status-0-13" podUID=a409f0f6-ac57-4d5e-95e1-97e074ea74b7
Oct 05 17:41:10 kind-worker kubelet[248]: I1005 17:41:10.116535     248 status_manager.go:650] "Pod fully terminated and removed from etcd" pod="pods-7829/pod-submit-status-0-13"
Oct 05 17:41:10 kind-worker kubelet[248]: I1005 17:41:10.119678     248 kubelet.go:2065] "SyncLoop REMOVE" source="api" pods=[pods-7829/pod-submit-status-0-13]
Oct 05 17:41:10 kind-worker kubelet[248]: I1005 17:41:10.119730     248 kubelet.go:1910] "Pod has been deleted and must be killed" pod="pods-7829/pod-submit-status-0-13" podUID=a409f0f6-ac57-4d5e-95e1-97e074ea74b7
Oct 05 17:41:10 kind-worker kubelet[248]: I1005 17:41:10.119758     248 pod_workers.go:557] "Pod is finished processing, no further updates" pod="pods-7829/pod-submit-status-0-13" podUID=a409f0f6-ac57-4d5e-95e1-97e074ea74b7

This just seems like accidental bad timing to me and unrelated to the PR... thoughts?

Attached:
pod-submit-status-0-13.log

from https://storage.googleapis.com/kubernetes-jenkins/pr-logs/pull/105462/pull-kubernetes-e2e-kind/1445439136864407552/artifacts/logs/kind-worker/kubelet.log

- Update test to account for late synced statuses - Terminated containers are not running - Add missing format values to test logline

ehashman · 2021-10-05T18:53:10Z

test/e2e/node/pods.go

@@ -425,7 +427,7 @@ var _ = SIGDescribe("Pods Extended", func() {
 							if !hasTerminalPhase {
 								var names []string
 								for _, status := range pod.Status.ContainerStatuses {
-									if status.State.Terminated != nil || status.State.Running != nil {
+									if status.State.Running != nil {


I think this was just wrong before, but we never hit it because we were failing to sync out terminated container statuses. Now that we're doing that correctly, a Pending pod with a terminated container (perhaps because it was deleted before it reached Running) would cause this test to fail.

Note: this line came from #88440 which explicitly says in the description "The kubelet will consider any container without the waiting or terminated state to be still running, like it does for other operations." which doesn't match the code here.

ehashman · 2021-10-05T19:06:16Z

/test pull-kubernetes-node-kubelet-eviction
/test pull-kubernetes-node-kubelet-serial

ehashman · 2021-10-05T19:39:03Z

Passed tests 🥳

The serial tests will fail, just wanna take a quick look for signal.

smarterclayton · 2021-10-05T20:00:49Z

Are there any other optional jobs we should run?

ehashman · 2021-10-05T20:07:24Z

Don't think so.

smarterclayton · 2021-10-05T20:10:50Z

/lgtm
/approve

k8s-ci-robot · 2021-10-05T20:11:09Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: ehashman, smarterclayton

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~pkg/kubelet/OWNERS~~ [smarterclayton]
~~test/e2e/node/OWNERS~~ [ehashman,smarterclayton]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

…5462-upstream-release-1.22 Automated cherry pick of #105462: Ensure terminal pods maintain terminal status

k8s-ci-robot requested review from yifan-gu and yujuhong October 4, 2021 17:11

k8s-ci-robot added the area/kubelet label Oct 4, 2021

Do not sync Waiting statuses for Terminated pods

5ff6c23

ehashman force-pushed the merge-terminal-phase branch from 728f146 to e8b99f4 Compare October 4, 2021 18:41

k8s-ci-robot added size/M Denotes a PR that changes 30-99 lines, ignoring generated files. and removed size/S Denotes a PR that changes 10-29 lines, ignoring generated files. labels Oct 4, 2021

ehashman commented Oct 4, 2021

View reviewed changes

ehashman force-pushed the merge-terminal-phase branch from e8b99f4 to 77b4cb0 Compare October 4, 2021 19:44

k8s-ci-robot added size/L Denotes a PR that changes 100-499 lines, ignoring generated files. and removed size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Oct 4, 2021

ehashman changed the title ~~[WIP] Ensure terminal pods maintain terminal status~~ Ensure terminal pods maintain terminal status Oct 4, 2021

k8s-ci-robot removed the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Oct 4, 2021

ehashman force-pushed the merge-terminal-phase branch from 77b4cb0 to c32e569 Compare October 4, 2021 19:58

ehashman mentioned this pull request Oct 4, 2021

[WIP] Correctly set terminated pods phase, reason, message, and statuses #105411

Closed

smarterclayton reviewed Oct 4, 2021

View reviewed changes

pkg/kubelet/kubelet_pods_test.go Show resolved Hide resolved

k8s-ci-robot added triage/accepted Indicates an issue or PR is ready to be actively worked on. and removed needs-triage Indicates an issue or PR lacks a `triage/foo` label and requires one. labels Oct 4, 2021

ehashman added this to Needs Reviewer in SIG Node PR Triage Oct 4, 2021

Fix bugs in e2e pod test

f9a827b

- Update test to account for late synced statuses - Terminated containers are not running - Add missing format values to test logline

ehashman force-pushed the merge-terminal-phase branch from 2cb2ae6 to f9a827b Compare October 5, 2021 18:51

ehashman commented Oct 5, 2021

View reviewed changes

k8s-ci-robot assigned smarterclayton Oct 5, 2021

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Oct 5, 2021

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Oct 5, 2021

k8s-ci-robot merged commit 907d62e into kubernetes:master Oct 5, 2021

SIG Node PR Triage automation moved this from Needs Reviewer to Done Oct 5, 2021

k8s-ci-robot added this to the v1.23 milestone Oct 5, 2021

ehashman mentioned this pull request Oct 5, 2021

Automated cherry pick of #105462: Ensure terminal pods maintain terminal status #105496

Merged

k8s-ci-robot added a commit that referenced this pull request Oct 8, 2021

Merge pull request #105496 from ehashman/automated-cherry-pick-of-#10…

b09e26c

…5462-upstream-release-1.22 Automated cherry pick of #105462: Ensure terminal pods maintain terminal status

249043822 mentioned this pull request Oct 9, 2021

Kubectl reports wrong status for evicted pod when container statuses are synced after #105467

Open

openshift-ci-robot mentioned this pull request Oct 29, 2021

Bug 2018516: 4.9: bump(github.com/openshift/*): make go.{mod,sum} point to 1.22.1 openshift/kubernetes#1026

Closed

This was referenced Nov 10, 2021

Updating openshift-enterprise-pod images to be consistent with ART openshift/kubernetes#933

Merged

Updating openshift-enterprise-hyperkube images to be consistent with ART openshift/kubernetes#934

Merged

smarterclayton mentioned this pull request Mar 1, 2022

Delay writing a terminal phase until the pod is terminated #108366

Merged

gautierdelorme mentioned this pull request Mar 16, 2022

Waiting containers are marked as Terminated on pod failure #108733

Closed

breunigs mentioned this pull request May 12, 2022

Pods with failed status IP address reused on new pods, but traffic still going to old pods across namespaces. #109414

Closed

aheng-ch mentioned this pull request Aug 2, 2022

Remove redundant check for illegal phase transition #111624

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Ensure terminal pods maintain terminal status #105462

Ensure terminal pods maintain terminal status #105462

ehashman commented Oct 4, 2021

ehashman commented Oct 4, 2021

ehashman Oct 4, 2021

rphillips commented Oct 4, 2021

rphillips commented Oct 4, 2021

ehashman commented Oct 5, 2021 •

edited

ehashman Oct 5, 2021

ehashman Oct 5, 2021

ehashman commented Oct 5, 2021

ehashman commented Oct 5, 2021

smarterclayton commented Oct 5, 2021

ehashman commented Oct 5, 2021

smarterclayton commented Oct 5, 2021

k8s-ci-robot commented Oct 5, 2021

Ensure terminal pods maintain terminal status #105462

Ensure terminal pods maintain terminal status #105462

Conversation

ehashman commented Oct 4, 2021

What type of PR is this?

What this PR does / why we need it:

Which issue(s) this PR fixes:

Special notes for your reviewer

Does this PR introduce a user-facing change?

Additional documentation e.g., KEPs (Kubernetes Enhancement Proposals), usage docs, etc.:

ehashman commented Oct 4, 2021

ehashman Oct 4, 2021

Choose a reason for hiding this comment

rphillips commented Oct 4, 2021

rphillips commented Oct 4, 2021

ehashman commented Oct 5, 2021 • edited

ehashman Oct 5, 2021

Choose a reason for hiding this comment

ehashman Oct 5, 2021

Choose a reason for hiding this comment

ehashman commented Oct 5, 2021

ehashman commented Oct 5, 2021

smarterclayton commented Oct 5, 2021

ehashman commented Oct 5, 2021

smarterclayton commented Oct 5, 2021

k8s-ci-robot commented Oct 5, 2021

ehashman commented Oct 5, 2021 •

edited