Skip to content

Prevent pods from defaulting to zero second grace periods#102025

Closed
smarterclayton wants to merge 5 commits into
kubernetes:masterfrom
smarterclayton:delete_safety
Closed

Prevent pods from defaulting to zero second grace periods#102025
smarterclayton wants to merge 5 commits into
kubernetes:masterfrom
smarterclayton:delete_safety

Conversation

@smarterclayton

@smarterclayton smarterclayton commented May 14, 2021

Copy link
Copy Markdown
Contributor

A zero second grace period on pods is a special value and is intended for exceptional use (to break the safety guarantees when a node is partitioned). When spec.terminationGracePeriodSeconds (which overrides the default of 30s) is zero, pods are instantly deleted without waiting for the kubelet to ensure the process is not running. The intent of this default was not to allow users to bypass that process (since the normal behavior of a pod is not to bypass kubelet shutdown) and the documentation was written as such. Users who wish to bypass the kubelet's participation must set gracePeriod to zero on the delete options call.

With this change the value 1 second is substituted when users specify 0, resulting in the kubelet participating in the deletion process and only a minor delay in practice.

The controlling design for pod safety is https://github.com/kubernetes/community/blob/master/contributors/design-proposals/storage/pod-safety.md and I believe we simply missed this during the early review and no one ever blew themselves up with this footgun. We did not intend to offer the footgun as a feature of defaulting as described here in the doc:

A user may specify an interval on the pod called the termination grace period that defines the minimum amount of time the pod will have to complete the termination phase, and all components will honor this interval.

That matches the value we placed in the field godoc:

The grace period is the duration in seconds after the processes running in the pod are sent a termination signal and the time when the processes are forcibly halted with a kill signal.

The intent was the default is the minimum, that the kubelet would be involved in deletion, and that gracePeriod=0 on a delete operation was the only way a user would be able to perform force delete. Unfortunately we didn't actually handle 0 specially at the time we implemented this and it has remained ambiguous since then.

As this changes the observed behavior of the system (prioritizing safety and the documented behavior over the unsafe behavior), this is also an API change. Kube is consistent by default, and bypassing the kubelet is both a safety (accidental consistency loss) and operational hazard (deleting a large number of pods without the kubelet means that resources are still allotted to those workers and could take an arbitrary amount of time to clean up).

Discovered while doing a review of clusters in the wild - some workloads were setting this thinking that it simply meant "as fast as possible".

/kind bug
/kind api-change
/sig node

The pod `spec.terminationGracePeriodSeconds` field unintentionally allowed a zero value to be copied directly to the pod during deletion, causing the pod to bypass kubelet shutdown during deletion (aka force deletion). This was unintentional - force deletion was only meant to be possible on an explicit delete with the gracePeriod field provided to delete options.  Pods with `spec.terminationGracePeriodSeconds=0` now are interpreted the same as `spec.terminationGracePeriodSeconds=1` and will no longer be deleted without the kubelet having a chance to clean up the pod.  The kubelet will shut the pod down as fast as it can, and force deleting a pod is now only possible by invoking delete or delete collection on pods with the gracePeriod=0 field.  

@k8s-ci-robot k8s-ci-robot added kind/bug Categorizes issue or PR as related to a bug. size/L Denotes a PR that changes 100-499 lines, ignoring generated files. kind/api-change Categorizes issue or PR as related to adding, removing, or otherwise changing an API do-not-merge/release-note-label-needed Indicates that a PR should not merge because it's missing one of the release note labels. cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. do-not-merge/needs-sig Indicates an issue or PR lacks a `sig/foo` label and requires one. needs-triage Indicates an issue or PR lacks a `triage/foo` label and requires one. needs-priority Indicates a PR lacks a `priority/foo` label and requires one. labels May 14, 2021
@k8s-ci-robot k8s-ci-robot requested review from deads2k and justinsb May 14, 2021 23:08
@k8s-ci-robot k8s-ci-robot added approved Indicates a PR has been approved by an approver from all required OWNERS files. release-note Denotes a PR that will be considered when it comes time to generate release notes. and removed do-not-merge/release-note-label-needed Indicates that a PR should not merge because it's missing one of the release note labels. labels May 14, 2021
@smarterclayton

Copy link
Copy Markdown
Contributor Author

/assign @liggitt
/assign @derekwaynecarr

@fejta-bot

Copy link
Copy Markdown

This PR may require API review.

If so, when the changes are ready, complete the pre-review checklist and request an API review.

Status of requested reviews is tracked in the API Review project.

@smarterclayton

Copy link
Copy Markdown
Contributor Author

/priority important-soon

@k8s-ci-robot k8s-ci-robot added priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release. and removed needs-priority Indicates a PR lacks a `priority/foo` label and requires one. labels May 14, 2021
@smarterclayton

Copy link
Copy Markdown
Contributor Author

Wow, we have e2e tests that are racing on the same pod name: https://prow.k8s.io/view/gs/kubernetes-jenkins/pr-logs/pull/102025/pull-kubernetes-e2e-kind-ipv6/1393342213345251328



Kubernetes e2e suite: [sig-network] Services should implement service.kubernetes.io/service-proxy-name expand_less | 1m31s
-- | --
/home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/network/service.go:1883 May 14 23:32:30.493: Unexpected error:     <*errors.StatusError \| 0xc0008e59a0>: {         ErrStatus: {             TypeMeta: {Kind: "", APIVersion: ""},             ListMeta: {                 SelfLink: "",                 ResourceVersion: "",                 Continue: "",                 RemainingItemCount: nil,             },             Status: "Failure",             Message: "object is being deleted: pods \"verify-service-down-host-exec-pod\" already exists",             Reason: "AlreadyExists",             Details: {                 Name: "verify-service-down-host-exec-pod",                 Group: "",                 Kind: "pods",                 UID: "",                 Causes: nil,                 RetryAfterSeconds: 0,             },             Code: 409,         },     }     object is being deleted: pods "verify-service-down-host-exec-pod" already exists occurred /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/network/service.go:2705

These tests were force deleting pods, then starting a pod of the same name and execing to it - which wouldn't necessarily guarantee that an exec session was even going to the new pod (at least, historically it wouldn't). I will fix the e2e tests that assume that deletion like this is safe (it isn't)

@k8s-ci-robot k8s-ci-robot added area/test sig/network Categorizes an issue or PR as relevant to SIG Network. sig/testing Categorizes an issue or PR as relevant to SIG Testing. sig/apps Categorizes an issue or PR as relevant to SIG Apps. and removed do-not-merge/needs-sig Indicates an issue or PR lacks a `sig/foo` label and requires one. labels May 15, 2021
@dims

dims commented May 15, 2021

Copy link
Copy Markdown
Member

/hold

for reviews and prevent accidental merging :)

@k8s-ci-robot k8s-ci-robot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label May 15, 2021
@smarterclayton

smarterclayton commented May 15, 2021

Copy link
Copy Markdown
Contributor Author

Kubernetes e2e suite: [sig-api-machinery] Garbage collector should keep the rc around until all its pods are deleted if the deleteOptions says so in https://prow.k8s.io/view/gs/kubernetes-jenkins/pr-logs/pull/102025/pull-kubernetes-e2e-kind-ipv6/1393391901620572160 is broken because it's taking over 1m30s minutes to delete 10 pods that have single second termination grace period. That's a very long time - it points to either kubelet teardown issues (several of which exist and I suspect there may be containerd issues not diagnosed) or another issue with qps. Looking at the pod remaining on the first worker:

May 15 02:42:53 kind-worker kubelet[251]: I0515 02:42:53.451499     251 kubelet.go:1948] "SyncLoop DELETE" source="api" pods=[gc-4860/simpletest.rc-2mlnf]
...
May 15 02:43:11 kind-worker kubelet[251]: I0515 02:43:11.814953     251 kubelet_pods.go:967] "Pod is terminated, but some containers are still running" pod="gc-4860/simpletest.rc-2mlnf"
...
May 15 02:44:16 kind-worker kubelet[251]: I0515 02:44:16.382949     251 kuberuntime_container.go:714] "Killing container with a grace period override" pod="gc-4860/simpletest.rc-2mlnf" podUID=ae1207d1-5e23-4844-aff1-8e5a6ee2b160 containerName="nginx" containerID="containerd://5aa9bb1fe965bfc14eb5f8ddeab3f0a22362c795b4b9ebba3656d8d9a91a0d57" gracePeriod=2
...
# this takes FAR too long - what is going on
...
May 15 02:44:16 kind-worker kubelet[251]: I0515 02:44:16.383385     251 event.go:291] "Event occurred" object="gc-4860/simpletest.rc-2mlnf" kind="Pod" apiVersion="v1" type="Normal" reason="Killing" message="Stopping container nginx"
May 15 02:44:16 kind-worker kubelet[251]: I0515 02:44:16.532080     251 kuberuntime_container.go:722] "Container exited normally" pod="gc-4860/simpletest.rc-2mlnf" podUID=ae1207d1-5e23-4844-aff1-8e5a6ee2b160 containerName="nginx" containerID="containerd://5aa9bb1fe965bfc14eb5f8ddeab3f0a22362c795b4b9ebba3656d8d9a91a0d57"

This implies we have a kubelet bug where some events are being lost / the worker is saturated, or a call is failing in containerd. Needs investigation. This is yet another reason why force delete in e2e hides SLO failures in underlying components - I would expect subsecond container kills from time the delete is received, even if volume cleanup takes longer.

Something very wrong / inadequate is happening in code + environment. @rphillips can you help me find an owner to run down what would cause the kubelet to get this bogged down (might be container runtime, hard to say).

@aojea

aojea commented Aug 10, 2021

Copy link
Copy Markdown
Member

@smarterclayton it needs some tuning hack/update-openapi-spec.sh

All that being said, yes this should be targeted for 1.23 because it's a change to the behavior of the system and we will need time to go find all the issues that force deletion was hiding.

I think we should merge this as soon as possible

@smarterclayton

Copy link
Copy Markdown
Contributor Author

Talking with jordan he suggested three things:

  1. a warning
  2. a feature gate to control the change
  3. a metric

all of which are reasonable as we are changing the behavior of the system and it might impact someone creating a pod and then deleting and expect immediate deletion (due to the implicit zero). I'm going to draft a KEP which clarifies the behavior and brings in pod safety rules (still the original guiding element).

The zero grace period is a special value and is intended for
exceptional use (to break the safety guarantees when a node
is partitioned). When spec.terminationGracePeriodSeconds is zero,
pods are instantly deleted without waiting for the kubelet to
ensure the process is not running. The intent of this default
was not to allow users to bypass that process (since the normal
behavior of a pod is not to violate kubelet shutdown) and the
documentation was written as such. Users who wish to bypass
the kubelet's participation must set gracePeriod to zero on
the delete options call.

The value one is substituted when users specify 0, resulting
in the kubelet participating in the deletion process and only
a minor delay.
The kubelet owns termination of scheduled pods. In integration
tests, run pod deletion on pods that have requested termination
as necessary.
Previously these tests were relying on force deletion, which allowed
new pods with the same name to be created before the pods on the
nodes completed. This meant that a test that did:

1. create pod foo/bar
2. exec pod foo/bar "run some test"
3. delete pod foo/bar (force)
4. create pod foo/bar
5. exec pod foo/bar "some other test"

could end up execing into the terminating container if the delete
notification was delayed on watch.
Now that pods are not force deleted, some tests that wait for pods
to be deleted take a realistic amount of time, which is about a
minute from deletion request to kubelet finally being able to
delete the pod from etcd due to latency in the status pipeline
in dense e2e tests.

Increase the timeout of this test to two minutes.
@k8s-ci-robot

Copy link
Copy Markdown
Contributor

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: smarterclayton

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

The pull request process is described here

Details Needs approval from an approver in each of these files:

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

@smarterclayton

Copy link
Copy Markdown
Contributor Author

Hrm, there's a very interesting bug in https://prow.k8s.io/view/gs/kubernetes-jenkins/pr-logs/pull/102025/pull-kubernetes-e2e-kind-ipv6/1498726712261742592:

Kubernetes  e2e suite: [sig-network] Proxy version v1 A set of valid responses are  returned for both pod and service Proxy [Conformance] expand_less | 1m2s
-- | --
/home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:633 Mar  1 18:56:13.682: Pod didn't start within time out period Unexpected error:     <*errors.errorString \| 0xc000210250>: {         s: "timed out waiting for the condition",     }     timed out waiting for the condition occurred /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/network/proxy.go:408

The status update for agnhost is delivered to the kubelet (we detect that container agnhost started and thus transition the phase to running) but then the kubelet logs show that the status update was "unchanged" at 18:55:34.494020 and then at 18:55:56.088086 we sent a patch that shows the container in waiting. I think this is head of line blocking that #107897 fixes (we put status updates in a queue and read them in order, but we really only need the most recent status). If so, unrelated to this PR.

Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.324498     262 kubelet.go:2077] "SyncLoop (PLEG): event for pod" pod="proxy-4151/agnhost" event=&{ID:d54c3888-9dd2-410f-9713-0b94cfc44bc0 Type:ContainerStarted Data:15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3}
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325199     262 kubelet.go:1488] "syncPod enter" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325214     262 kubelet_pods.go:1429] "Generating pod status" pod="proxy-4151/agnhost"
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325243     262 kubelet_pods.go:1441] "Got phase for pod" pod="proxy-4151/agnhost" oldPhase=Pending phase=Running
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325565     262 volume_manager.go:404] "Waiting for volumes to attach and mount for pod" pod="proxy-4151/agnhost"
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325630     262 volume_manager.go:435] "All volumes are attached and mounted for pod" pod="proxy-4151/agnhost"
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325767     262 kuberuntime_manager.go:712] "computePodActions got for pod" podActions={KillPod:false CreateSandbox:false SandboxID:d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1 Attempt:0 NextInitContainerToStart:nil ContainersToStart:[] ContainersToKill:map[] EphemeralContainersToStart:[]} pod="proxy-4151/agnhost"
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325899     262 kubelet.go:1712] "syncPod exit" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325929     262 pod_workers.go:979] "Processing pod event done" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 updateType=0
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.325941     262 pod_workers.go:888] "Processing pod event" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 updateType=0
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.413079     262 desired_state_of_world_populator.go:317] "Added volume to desired state" pod="proxy-4151/agnhost" volumeName="kube-api-access-nvjrs" volumeSpecName="kube-api-access-nvjrs"
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.426072     262 reconciler.go:247] "Starting operationExecutor.MountVolume for volume \"kube-api-access-nvjrs\" (UniqueName: \"kubernetes.io/projected/d54c3888-9dd2-410f-9713-0b94cfc44bc0-kube-api-access-nvjrs\") pod \"agnhost\" (UID: \"d54c3888-9dd2-410f-9713-0b94cfc44bc0\") Volume is already mounted to pod, but remount was requested." pod="proxy-4151/agnhost"
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.426826     262 projected.go:183] Setting up volume kube-api-access-nvjrs for pod d54c3888-9dd2-410f-9713-0b94cfc44bc0 at /var/lib/kubelet/pods/d54c3888-9dd2-410f-9713-0b94cfc44bc0/volumes/kubernetes.io~projected/kube-api-access-nvjrs
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.427050     262 atomic_writer.go:161] pod proxy-4151/agnhost volume kube-api-access-nvjrs: no update required for target directory /var/lib/kubelet/pods/d54c3888-9dd2-410f-9713-0b94cfc44bc0/volumes/kubernetes.io~projected/kube-api-access-nvjrs
Mar 01 18:55:33 kind-worker2 kubelet[262]: I0301 18:55:33.427081     262 operation_generator.go:739] "MountVolume.SetUp succeeded for volume \"kube-api-access-nvjrs\" (UniqueName: \"kubernetes.io/projected/d54c3888-9dd2-410f-9713-0b94cfc44bc0-kube-api-access-nvjrs\") pod \"agnhost\" (UID: \"d54c3888-9dd2-410f-9713-0b94cfc44bc0\") " pod="proxy-4151/agnhost"
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.493569     262 kubelet.go:1488] "syncPod enter" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.493588     262 kubelet_pods.go:1429] "Generating pod status" pod="proxy-4151/agnhost"
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.493640     262 kubelet_pods.go:1441] "Got phase for pod" pod="proxy-4151/agnhost" oldPhase=Running phase=Running
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.494020     262 status_manager.go:475] "Ignoring same status for pod" pod="proxy-4151/agnhost" status={Phase:Running Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-03-01 18:55:13 +0000 UTC Reason: Message:} {Type:Ready Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-03-01 18:55:33 +0000 UTC Reason: Message:} {Type:ContainersReady Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-03-01 18:55:33 +0000 UTC Reason: Message:} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-03-01 18:55:13 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:fc00:f853:ccd:e793::3 PodIP:fd00:10:244:1::f6 PodIPs:[{IP:fd00:10:244:1::f6}] StartTime:2022-03-01 18:55:13 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:agnhost State:{Waiting:nil Running:&ContainerStateRunning{StartedAt:2022-03-01 18:55:33 +0000 UTC,} Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:nil} Ready:true RestartCount:0 Image:k8s.gcr.io/e2e-test-images/agnhost:2.33 ImageID:k8s.gcr.io/e2e-test-images/agnhost@sha256:5b3a9f1c71c09c00649d8374224642ff7029ce91a721ec9132e6ed45fa73fd43 ContainerID:containerd://15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3 Started:0xc0034c6899}] QOSClass:BestEffort EphemeralContainerStatuses:[]}
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.494256     262 volume_manager.go:404] "Waiting for volumes to attach and mount for pod" pod="proxy-4151/agnhost"
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.494358     262 volume_manager.go:435] "All volumes are attached and mounted for pod" pod="proxy-4151/agnhost"
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.494522     262 kuberuntime_manager.go:712] "computePodActions got for pod" podActions={KillPod:false CreateSandbox:false SandboxID:d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1 Attempt:0 NextInitContainerToStart:nil ContainersToStart:[] ContainersToKill:map[] EphemeralContainersToStart:[]} pod="proxy-4151/agnhost"
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.494649     262 kubelet.go:1712] "syncPod exit" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.494694     262 pod_workers.go:979] "Processing pod event done" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 updateType=0
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.545019     262 desired_state_of_world_populator.go:317] "Added volume to desired state" pod="proxy-4151/agnhost" volumeName="kube-api-access-nvjrs" volumeSpecName="kube-api-access-nvjrs"
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.644813     262 reconciler.go:247] "Starting operationExecutor.MountVolume for volume \"kube-api-access-nvjrs\" (UniqueName: \"kubernetes.io/projected/d54c3888-9dd2-410f-9713-0b94cfc44bc0-kube-api-access-nvjrs\") pod \"agnhost\" (UID: \"d54c3888-9dd2-410f-9713-0b94cfc44bc0\") Volume is already mounted to pod, but remount was requested." pod="proxy-4151/agnhost"
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.645072     262 projected.go:183] Setting up volume kube-api-access-nvjrs for pod d54c3888-9dd2-410f-9713-0b94cfc44bc0 at /var/lib/kubelet/pods/d54c3888-9dd2-410f-9713-0b94cfc44bc0/volumes/kubernetes.io~projected/kube-api-access-nvjrs
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.645372     262 atomic_writer.go:161] pod proxy-4151/agnhost volume kube-api-access-nvjrs: no update required for target directory /var/lib/kubelet/pods/d54c3888-9dd2-410f-9713-0b94cfc44bc0/volumes/kubernetes.io~projected/kube-api-access-nvjrs
Mar 01 18:55:34 kind-worker2 kubelet[262]: I0301 18:55:34.645409     262 operation_generator.go:739] "MountVolume.SetUp succeeded for volume \"kube-api-access-nvjrs\" (UniqueName: \"kubernetes.io/projected/d54c3888-9dd2-410f-9713-0b94cfc44bc0-kube-api-access-nvjrs\") pod \"agnhost\" (UID: \"d54c3888-9dd2-410f-9713-0b94cfc44bc0\") " pod="proxy-4151/agnhost"
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.113992     262 factory.go:258] Using factory "containerd" for container "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3"
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.115400     262 manager.go:988] Added container: "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3" (aliases: [15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3 /docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3], namespace: "containerd")
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.115691     262 handler.go:325] Added event &{/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3 2022-03-01 18:55:32.949377956 +0000 UTC containerCreation {<nil>}}
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.115744     262 container.go:531] Start housekeeping for container "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3"
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.143145     262 factory.go:258] Using factory "containerd" for container "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1"
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.144665     262 manager.go:988] Added container: "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1" (aliases: [d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1 /docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1], namespace: "containerd")
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.144930     262 handler.go:325] Added event &{/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1 2022-03-01 18:55:28.305058425 +0000 UTC containerCreation {<nil>}}
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.145005     262 container.go:531] Start housekeeping for container "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1"
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.166532     262 factory.go:262] Factory "containerd" was unable to handle container "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0"
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.166539     262 factory.go:262] Factory "systemd" was unable to handle container "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0"
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.166550     262 factory.go:255] Factory "raw" can handle container "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0", but ignoring.
Mar 01 18:55:49 kind-worker2 kubelet[262]: I0301 18:55:49.166558     262 manager.go:925] ignoring container "/docker/9a00b8cc23eec20d1be7279e14bf116ccfc1b327bdbc59425d24cfdcd2fac1ca/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0"
Mar 01 18:55:55 kind-worker2 kubelet[262]: I0301 18:55:55.866672     262 request.go:519] Waited for 192.688646ms due to client-side throttling, not priority and fairness, request: GET:https://kind-control-plane:6443/api/v1/namespaces/proxy-4151/pods/agnhost
Mar 01 18:55:56 kind-worker2 kubelet[262]: I0301 18:55:56.066988     262 request.go:519] Waited for 197.368267ms due to client-side throttling, not priority and fairness, request: PATCH:https://kind-control-plane:6443/api/v1/namespaces/proxy-4151/pods/agnhost/status
Mar 01 18:55:56 kind-worker2 kubelet[262]: I0301 18:55:56.088086     262 status_manager.go:624] "Patch status for pod" pod="proxy-4151/agnhost" patch="{\"metadata\":{\"uid\":\"d54c3888-9dd2-410f-9713-0b94cfc44bc0\"},\"status\":{\"$setElementOrder/conditions\":[{\"type\":\"Initialized\"},{\"type\":\"Ready\"},{\"type\":\"ContainersReady\"},{\"type\":\"PodScheduled\"}],\"conditions\":[{\"lastProbeTime\":null,\"lastTransitionTime\":\"2022-03-01T18:55:13Z\",\"status\":\"True\",\"type\":\"Initialized\"},{\"lastProbeTime\":null,\"lastTransitionTime\":\"2022-03-01T18:55:13Z\",\"message\":\"containers with unready status: [agnhost]\",\"reason\":\"ContainersNotReady\",\"status\":\"False\",\"type\":\"Ready\"},{\"lastProbeTime\":null,\"lastTransitionTime\":\"2022-03-01T18:55:13Z\",\"message\":\"containers with unready status: [agnhost]\",\"reason\":\"ContainersNotReady\",\"status\":\"False\",\"type\":\"ContainersReady\"}],\"containerStatuses\":[{\"image\":\"k8s.gcr.io/e2e-test-images/agnhost:2.33\",\"imageID\":\"\",\"lastState\":{},\"name\":\"agnhost\",\"ready\":false,\"restartCount\":0,\"started\":false,\"state\":{\"waiting\":{\"reason\":\"ContainerCreating\"}}}],\"hostIP\":\"fc00:f853:ccd:e793::3\",\"startTime\":\"2022-03-01T18:55:13Z\"}}"
Mar 01 18:55:56 kind-worker2 kubelet[262]: I0301 18:55:56.088171     262 status_manager.go:633] "Status for pod updated successfully" pod="proxy-4151/agnhost" statusVersion=1 status={Phase:Pending Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-03-01 18:55:13 +0000 UTC Reason: Message:} {Type:Ready Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-03-01 18:55:13 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [agnhost]} {Type:ContainersReady Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-03-01 18:55:13 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [agnhost]} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-03-01 18:55:13 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:fc00:f853:ccd:e793::3 PodIP: PodIPs:[] StartTime:2022-03-01 18:55:13 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:agnhost State:{Waiting:&ContainerStateWaiting{Reason:ContainerCreating,Message:,} Running:nil Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:nil} Ready:false RestartCount:0 Image:k8s.gcr.io/e2e-test-images/agnhost:2.33 ImageID: ContainerID: Started:0xc00124d029}] QOSClass:BestEffort EphemeralContainerStatuses:[]}
Mar 01 18:55:56 kind-worker2 kubelet[262]: I0301 18:55:56.089865     262 kubelet.go:2052] "SyncLoop RECONCILE" source="api" pods=[proxy-4151/agnhost]
Mar 01 18:56:13 kind-worker2 kubelet[262]: I0301 18:56:13.697818     262 logs.go:320] "Finished parsing log file" path="/var/log/pods/proxy-4151_agnhost_d54c3888-9dd2-410f-9713-0b94cfc44bc0/agnhost/0.log"
Mar 01 18:56:13 kind-worker2 kubelet[262]: I0301 18:56:13.697880     262 httplog.go:131] "HTTP" verb="GET" URI="/containerLogs/proxy-4151/agnhost/agnhost?tailLines=42" latency="992.758µs" userAgent="Go-http-client/1.1" audit-ID="" srcIP="[fc00:f853:ccd:e793::4]:32930" resp=200
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123558     262 kubelet.go:2055] "SyncLoop DELETE" source="api" pods=[proxy-4151/agnhost]
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123608     262 pod_workers.go:625] "Pod is marked for graceful deletion, begin teardown" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123649     262 pod_workers.go:888] "Processing pod event" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 updateType=1
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123666     262 pod_workers.go:996] "Pod worker has observed request to terminate" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123696     262 kubelet.go:1719] "syncTerminatingPod enter" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123709     262 kubelet_pods.go:1429] "Generating pod status" pod="proxy-4151/agnhost"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123758     262 kubelet_pods.go:1441] "Got phase for pod" pod="proxy-4151/agnhost" oldPhase=Running phase=Running
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123848     262 kubelet.go:1749] "Pod terminating with grace period" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 gracePeriod=30
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123923     262 kuberuntime_container.go:718] "Killing container with a grace period override" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 containerName="agnhost" containerID="containerd://15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3" gracePeriod=30
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.123943     262 kuberuntime_container.go:722] "Killing container with a grace period" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 containerName="agnhost" containerID="containerd://15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3" gracePeriod=30
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.124019     262 event.go:294] "Event occurred" object="proxy-4151/agnhost" fieldPath="spec.containers{agnhost}" kind="Pod" apiVersion="v1" type="Normal" reason="Killing" message="Stopping container agnhost"
Mar 01 18:56:20 kind-worker2 kubelet[262]: E0301 18:56:20.125880     262 event.go:267] Server rejected event '&v1.Event{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"agnhost.16d856b08f64c0b0", GenerateName:"", Namespace:"proxy-4151", SelfLink:"", UID:"", ResourceVersion:"", Generation:0, CreationTimestamp:time.Date(1, time.January, 1, 0, 0, 0, 0, time.UTC), DeletionTimestamp:<nil>, DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string(nil), ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, InvolvedObject:v1.ObjectReference{Kind:"Pod", Namespace:"proxy-4151", Name:"agnhost", UID:"d54c3888-9dd2-410f-9713-0b94cfc44bc0", APIVersion:"v1", ResourceVersion:"17216", FieldPath:"spec.containers{agnhost}"}, Reason:"Killing", Message:"Stopping container agnhost", Source:v1.EventSource{Component:"kubelet", Host:"kind-worker2"}, FirstTimestamp:time.Date(2022, time.March, 1, 18, 56, 20, 123893936, time.Local), LastTimestamp:time.Date(2022, time.March, 1, 18, 56, 20, 123893936, time.Local), Count:1, Type:"Normal", EventTime:time.Date(1, time.January, 1, 0, 0, 0, 0, time.UTC), Series:(*v1.EventSeries)(nil), Action:"", Related:(*v1.ObjectReference)(nil), ReportingController:"", ReportingInstance:""}': 'events "agnhost.16d856b08f64c0b0" is forbidden: unable to create new content in namespace proxy-4151 because it is being terminated' (will not retry!)
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.161257     262 manager.go:1044] Destroyed container: "/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3" (aliases: [15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3 /kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3], namespace: "containerd")
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.161302     262 handler.go:325] Added event &{/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3 2022-03-01 18:56:20.16129489 +0000 UTC m=+511.863183509 containerDeletion {<nil>}}
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.217023     262 kuberuntime_container.go:731] "Container exited normally" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 containerName="agnhost" containerID="containerd://15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.283025     262 manager.go:1044] Destroyed container: "/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1" (aliases: [d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1 /kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1], namespace: "containerd")
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.283072     262 handler.go:325] Added event &{/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0/d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1 2022-03-01 18:56:20.283064772 +0000 UTC m=+511.984953383 containerDeletion {<nil>}}
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.643025     262 kuberuntime_manager.go:1035] "getSandboxIDByPodUID got sandbox IDs for pod" podSandboxID=[d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1] pod="proxy-4151/agnhost"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.644313     262 kubelet.go:1791] "Post-termination container state" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 containers=[{Name:agnhost State:exited ExitCode:2 FinishedAt:2022-03-01T18:56:20.13992941Z}]
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.644348     262 kubelet.go:1798] "Pod termination stopped all running containers" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.644378     262 kubelet.go:1800] "syncTerminatingPod exit" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.644393     262 pod_workers.go:1014] "Pod terminated all containers successfully" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.644420     262 pod_workers.go:979] "Processing pod event done" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 updateType=1
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.644433     262 pod_workers.go:888] "Processing pod event" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 updateType=2
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.645631     262 desired_state_of_world_populator.go:258] "Removing volume from desired state" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 volumeName="kube-api-access-nvjrs"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.736762     262 reconciler.go:192] "operationExecutor.UnmountVolume started for volume \"kube-api-access-nvjrs\" (UniqueName: \"kubernetes.io/projected/d54c3888-9dd2-410f-9713-0b94cfc44bc0-kube-api-access-nvjrs\") pod \"d54c3888-9dd2-410f-9713-0b94cfc44bc0\" (UID: \"d54c3888-9dd2-410f-9713-0b94cfc44bc0\") "
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.736811     262 subpath_linux.go:244] Cleaning up subpath mounts for /var/lib/kubelet/pods/d54c3888-9dd2-410f-9713-0b94cfc44bc0/volume-subpaths/kube-api-access-nvjrs
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.736872     262 projected.go:366] Tearing down volume kube-api-access-nvjrs for pod d54c3888-9dd2-410f-9713-0b94cfc44bc0 at /var/lib/kubelet/pods/d54c3888-9dd2-410f-9713-0b94cfc44bc0/volumes/kubernetes.io~projected/kube-api-access-nvjrs
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.737061     262 empty_dir_linux.go:99] Statfs_t of /var/lib/kubelet/pods/d54c3888-9dd2-410f-9713-0b94cfc44bc0/volumes/kubernetes.io~projected/kube-api-access-nvjrs: {Type:16914836 Bsize:4096 Blocks:13369771 Bfree:13369768 Bavail:13369768 Files:6684885 Ffree:6684876 Fsid:{Val:[0 0]} Namelen:255 Frsize:4096 Flags:4128 Spare:[0 0 0 0]}
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.737107     262 mount_linux.go:294] Unmounting /var/lib/kubelet/pods/d54c3888-9dd2-410f-9713-0b94cfc44bc0/volumes/kubernetes.io~projected/kube-api-access-nvjrs
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.739707     262 operation_generator.go:899] UnmountVolume.TearDown succeeded for volume "kubernetes.io/projected/d54c3888-9dd2-410f-9713-0b94cfc44bc0-kube-api-access-nvjrs" (OuterVolumeSpecName: "kube-api-access-nvjrs") pod "d54c3888-9dd2-410f-9713-0b94cfc44bc0" (UID: "d54c3888-9dd2-410f-9713-0b94cfc44bc0"). InnerVolumeSpecName "kube-api-access-nvjrs". PluginName "kubernetes.io/projected", VolumeGidValue ""
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.758960     262 generic.go:155] "GenericPLEG" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 containerID="15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3" oldState=running newState=exited
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.758993     262 generic.go:155] "GenericPLEG" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 containerID="d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1" oldState=running newState=exited
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.759620     262 kuberuntime_manager.go:1035] "getSandboxIDByPodUID got sandbox IDs for pod" podSandboxID=[d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1] pod="proxy-4151/agnhost"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.760871     262 generic.go:418] "PLEG: Write status" pod="proxy-4151/agnhost"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.760932     262 generic.go:296] "Generic (PLEG): container finished" podID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 containerID="15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3" exitCode=2
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.760950     262 kubelet.go:1808] "syncTerminatedPod enter" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.760961     262 kubelet.go:2077] "SyncLoop (PLEG): event for pod" pod="proxy-4151/agnhost" event=&{ID:d54c3888-9dd2-410f-9713-0b94cfc44bc0 Type:ContainerDied Data:15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3}
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.760965     262 kubelet_pods.go:1429] "Generating pod status" pod="proxy-4151/agnhost"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.760985     262 kubelet.go:2077] "SyncLoop (PLEG): event for pod" pod="proxy-4151/agnhost" event=&{ID:d54c3888-9dd2-410f-9713-0b94cfc44bc0 Type:ContainerDied Data:d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1}
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.760998     262 kubelet_pods.go:1441] "Got phase for pod" pod="proxy-4151/agnhost" oldPhase=Running phase=Failed
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.761044     262 volume_manager.go:444] "Waiting for volumes to unmount for pod" pod="proxy-4151/agnhost"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.761107     262 volume_manager.go:471] "All volumes are unmounted for pod" pod="proxy-4151/agnhost"
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.761115     262 kubelet.go:1821] "Pod termination unmounted volumes" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.763323     262 kubelet.go:1842] "Pod termination removed cgroups" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.763431     262 kubelet.go:1847] "Pod is terminated and will need no more status updates" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.763442     262 kubelet.go:1849] "syncTerminatedPod exit" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.763451     262 pod_workers.go:1069] "Pod is complete and the worker can now stop" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.763484     262 pod_workers.go:957] "Processing pod event done" pod="proxy-4151/agnhost" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 updateType=2
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.763337     262 manager.go:1044] Destroyed container: "/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0" (aliases: [], namespace: "")
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.763499     262 handler.go:325] Added event &{/kubelet/kubepods/besteffort/podd54c3888-9dd2-410f-9713-0b94cfc44bc0 2022-03-01 18:56:20.763493445 +0000 UTC m=+512.465382050 containerDeletion {<nil>}}
Mar 01 18:56:20 kind-worker2 kubelet[262]: I0301 18:56:20.838324     262 reconciler.go:300] "Volume detached for volume \"kube-api-access-nvjrs\" (UniqueName: \"kubernetes.io/projected/d54c3888-9dd2-410f-9713-0b94cfc44bc0-kube-api-access-nvjrs\") on node \"kind-worker2\" DevicePath \"\""
Mar 01 18:56:21 kind-worker2 kubelet[262]: I0301 18:56:21.765195     262 generic.go:155] "GenericPLEG" podUID=d54c3888-9dd2-410f-9713-0b94cfc44bc0 containerID="15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3" oldState=exited newState=non-existent
Mar 01 18:56:21 kind-worker2 kubelet[262]: I0301 18:56:21.797965     262 kuberuntime_manager.go:1035] "getSandboxIDByPodUID got sandbox IDs for pod" podSandboxID=[d8eebef8cac27edd498e15b54767774d9529278815a9b25c3730488f4642cbd1] pod="proxy-4151/agnhost"
Mar 01 18:56:21 kind-worker2 kubelet[262]: I0301 18:56:21.798925     262 generic.go:418] "PLEG: Write status" pod="proxy-4151/agnhost"
Mar 01 18:56:24 kind-worker2 kubelet[262]: I0301 18:56:24.866456     262 request.go:519] Waited for 359.411956ms due to client-side throttling, not priority and fairness, request: GET:https://kind-control-plane:6443/api/v1/namespaces/proxy-4151/pods/agnhost
Mar 01 18:56:26 kind-worker2 kubelet[262]: I0301 18:56:26.267554     262 request.go:519] Waited for 1.373835715s due to client-side throttling, not priority and fairness, request: PATCH:https://kind-control-plane:6443/api/v1/namespaces/proxy-4151/pods/agnhost/status
Mar 01 18:56:26 kind-worker2 kubelet[262]: I0301 18:56:26.300979     262 status_manager.go:624] "Patch status for pod" pod="proxy-4151/agnhost" patch="{\"metadata\":{\"uid\":\"d54c3888-9dd2-410f-9713-0b94cfc44bc0\"},\"status\":{\"$setElementOrder/conditions\":[{\"type\":\"Initialized\"},{\"type\":\"Ready\"},{\"type\":\"ContainersReady\"},{\"type\":\"PodScheduled\"}],\"conditions\":[{\"lastTransitionTime\":\"2022-03-01T18:55:33Z\",\"message\":null,\"reason\":null,\"status\":\"True\",\"type\":\"Ready\"},{\"lastTransitionTime\":\"2022-03-01T18:55:33Z\",\"message\":null,\"reason\":null,\"status\":\"True\",\"type\":\"ContainersReady\"}],\"containerStatuses\":[{\"containerID\":\"containerd://15b1f5ed1483cd823b1ca6a57448b4bc2943baec17200ceadbf44a11c4078dc3\",\"image\":\"k8s.gcr.io/e2e-test-images/agnhost:2.33\",\"imageID\":\"k8s.gcr.io/e2e-test-images/agnhost@sha256:5b3a9f1c71c09c00649d8374224642ff7029ce91a721ec9132e6ed45fa73fd43\",\"lastState\":{},\"name\":\"agnhost\",\"ready\":true,\"restartCount\":0,\"started\":true,\"state\":{\"running\":{\"startedAt\":\"2022-03-01T18:55:33Z\"}}}],\"phase\":\"Running\",\"podIP\":\"fd00:10:244:1::f6\",\"podIPs\":[{\"ip\":\"fd00:10:244:1::f6\"}]}}"

@k8s-ci-robot

Copy link
Copy Markdown
Contributor

@smarterclayton: PR needs rebase.

Details

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@k8s-triage-robot

Copy link
Copy Markdown

The Kubernetes project currently lacks enough contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Mark this issue or PR as fresh with /remove-lifecycle stale
  • Mark this issue or PR as rotten with /lifecycle rotten
  • Close this issue or PR with /close
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle stale

@k8s-triage-robot

Copy link
Copy Markdown

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Mark this issue or PR as fresh with /remove-lifecycle rotten
  • Close this issue or PR with /close
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle rotten

@k8s-triage-robot

Copy link
Copy Markdown

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Reopen this issue or PR with /reopen
  • Mark this issue or PR as fresh with /remove-lifecycle rotten
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close

@k8s-ci-robot

Copy link
Copy Markdown
Contributor

@k8s-triage-robot: Closed this PR.

Details

In response to this:

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Reopen this issue or PR with /reopen
  • Mark this issue or PR as fresh with /remove-lifecycle rotten
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@pohly

pohly commented Sep 22, 2022

Copy link
Copy Markdown
Contributor

/reopen

This is still relevant. I ran into this unexpected behavior of TerminationGracePeriodSeconds=0 recently and created a doc update to warn about it (#112564), but personally I would prefer to remove this obviously unintended footgun - i.e., let's revive this PR and merge that instead of my doc update.

@k8s-ci-robot

Copy link
Copy Markdown
Contributor

@pohly: Reopened this PR.

Details

In response to this:

/reopen

This is still relevant. I ran into this unexpected behavior of TerminationGracePeriodSeconds=0 recently and created a doc update to warn about it (#112564), but personally I would prefer to remove this obviously unintended footgun - i.e., let's revive this PR and merge that instead of my doc update.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@linux-foundation-easycla

linux-foundation-easycla Bot commented Sep 22, 2022

Copy link
Copy Markdown

CLA Signed

The committers listed above are authorized under a signed CLA.

@k8s-ci-robot

Copy link
Copy Markdown
Contributor

@smarterclayton: The following tests failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name Commit Details Required Rerun command
pull-kubernetes-e2e-gce-storage-slow f5f0066d5a7622fa5f8cfd03de3ef9d5943b4525 link /test pull-kubernetes-e2e-gce-storage-slow
pull-kubernetes-node-kubelet-serial-containerd c5d320c94bc376bc04e0252578f2793490e07bdd link /test pull-kubernetes-node-kubelet-serial-containerd
pull-kubernetes-node-kubelet-serial c5d320c94bc376bc04e0252578f2793490e07bdd link /test pull-kubernetes-node-kubelet-serial
pull-kubernetes-e2e-gci-gce-ingress 61aea54 link false /test pull-kubernetes-e2e-gci-gce-ingress
pull-kubernetes-e2e-ubuntu-gce-network-policies 61aea54 link false /test pull-kubernetes-e2e-ubuntu-gce-network-policies
pull-kubernetes-e2e-gce-ubuntu-containerd 61aea54 link true /test pull-kubernetes-e2e-gce-ubuntu-containerd
pull-kubernetes-e2e-gci-gce-ipvs 61aea54 link false /test pull-kubernetes-e2e-gci-gce-ipvs
pull-kubernetes-integration 61aea54 link true /test pull-kubernetes-integration
pull-kubernetes-conformance-kind-ipv6-parallel 61aea54 link false /test pull-kubernetes-conformance-kind-ipv6-parallel
pull-kubernetes-dependencies 61aea54 link true /test pull-kubernetes-dependencies
pull-kubernetes-node-e2e-containerd 61aea54 link true /test pull-kubernetes-node-e2e-containerd
pull-kubernetes-unit 61aea54 link true /test pull-kubernetes-unit
pull-kubernetes-e2e-kind-ipv6 61aea54 link true /test pull-kubernetes-e2e-kind-ipv6
pull-kubernetes-verify-govet-levee 61aea54 link true /test pull-kubernetes-verify-govet-levee
pull-kubernetes-conformance-kind-ga-only-parallel 61aea54 link true /test pull-kubernetes-conformance-kind-ga-only-parallel
pull-kubernetes-verify 61aea54 link true /test pull-kubernetes-verify
pull-kubernetes-e2e-gce-100-performance 61aea54 link true /test pull-kubernetes-e2e-gce-100-performance
pull-kubernetes-e2e-kind 61aea54 link true /test pull-kubernetes-e2e-kind
pull-kubernetes-typecheck 61aea54 link true /test pull-kubernetes-typecheck

Full PR test history. Your PR dashboard. Please help us cut down on flakes by linking to an open issue when you hit one in your PR.

Details

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. I understand the commands that are listed here.

@k8s-triage-robot

Copy link
Copy Markdown

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the PR is closed

You can:

  • Reopen this PR with /reopen
  • Mark this PR as fresh with /remove-lifecycle rotten
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close

@k8s-ci-robot

Copy link
Copy Markdown
Contributor

@k8s-triage-robot: Closed this PR.

Details

In response to this:

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the PR is closed

You can:

  • Reopen this PR with /reopen
  • Mark this PR as fresh with /remove-lifecycle rotten
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@pohly

pohly commented Jun 1, 2023

Copy link
Copy Markdown
Contributor

/reopen
/assign

@k8s-ci-robot

Copy link
Copy Markdown
Contributor

@pohly: Reopened this PR.

Details

In response to this:

/reopen
/assign

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@k8s-triage-robot

Copy link
Copy Markdown

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the PR is closed

You can:

  • Reopen this PR with /reopen
  • Mark this PR as fresh with /remove-lifecycle rotten
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close

@k8s-ci-robot

Copy link
Copy Markdown
Contributor

@k8s-triage-robot: Closed this PR.

Details

In response to this:

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the PR is closed

You can:

  • Reopen this PR with /reopen
  • Mark this PR as fresh with /remove-lifecycle rotten
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

approved Indicates a PR has been approved by an approver from all required OWNERS files. area/code-generation area/kubelet area/test cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. kind/api-change Categorizes issue or PR as related to adding, removing, or otherwise changing an API kind/bug Categorizes issue or PR as related to a bug. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release. release-note Denotes a PR that will be considered when it comes time to generate release notes. sig/api-machinery Categorizes an issue or PR as relevant to SIG API Machinery. sig/apps Categorizes an issue or PR as relevant to SIG Apps. sig/network Categorizes an issue or PR as relevant to SIG Network. sig/node Categorizes an issue or PR as relevant to SIG Node. sig/storage Categorizes an issue or PR as relevant to SIG Storage. sig/testing Categorizes an issue or PR as relevant to SIG Testing. size/L Denotes a PR that changes 100-499 lines, ignoring generated files. triage/accepted Indicates an issue or PR is ready to be actively worked on.

Projects

Archived in project

Development

Successfully merging this pull request may close these issues.