Repository: kubernetes
Issue: Pod phase transition is slower when EventedPLEG is enabled
Labels: kind/bug,sig/node,priority/important-longterm,triage/accepted

### What happened?
After #124297, which fixes timestamps set by Evented PLEG, was merged, a pod phase transition is slower especially at deletion when the EventedPLEG is enabled.

EventedPLEG is enabled:
```
$ kubectl create -f simple-pod.yaml; kubectl get pod simple-pod -w & kubectl wait --for=jsonpath='{.status.phase}'=Running pod simple-pod; sleep 1; kubectl delete pod simple-pod; kill $!
pod/simple-pod created
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	3s
pod/simple-pod condition met
simple-pod   1/1 	Terminating     	0      	4s
pod "simple-pod" deleted
simple-pod   0/1 	Terminating     	0      	13s
simple-pod   0/1 	Terminating     	0      	18s
simple-pod   0/1 	Terminating     	0      	18s
simple-pod   0/1 	Terminating     	0      	18s
```

EventedPLEG is disabled:
```
$ kubectl create -f simple-pod.yaml; kubectl get pod simple-pod -w & kubectl wait --for=jsonpath='{.status.phase}'=Running pod simple-pod; sleep 1; kubectl delete pod simple-pod; kill $!
pod/simple-pod created
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
```

As described here, a pod worker is blocked at `cache.GetNewerThan()` when it is woken up by an update without a cache update in a PLEG:
https://github.com/kubernetes/kubernetes/blob/ade0d2140a68a69f5343c865792393a83c76ca6a/pkg/kubelet/pod_workers.go#L1244-L1253

The worker is unblocked when another event is delivered or the PLEG calls `cache.UpdateTime()`. At the latter case, while the genericPLEG calls `cache.UpdateTime()` every one second along with `Relist()`, the EventPLEG calls `cache.UpdateTime()` every five seconds. Because of this difference, the Evented PLEG spends more time to get pods into another phase.

https://github.com/kubernetes/kubernetes/blob/ade0d2140a68a69f5343c865792393a83c76ca6a/pkg/kubelet/pleg/evented.go#L34-L37

Even if there is a cache update, a worker can be blocked when the cache is updated by an asynchronous event before the worker finishes `SyncPod()`. For instance, when a runtime starts a container, the PLEG gets an event and caches the container status(`running`). If this event is received after a pod worker finishes `SyncPod()` to start the container, the worker gets the new status at `GetNewerThan()` soon and runs `SyncPod()` again to update the pod phase to `running`. However, if the event arrives before the worker finishes `SyncPod()` to start the container, the worker is blocked at `GetNewerThan()` because the cached status is older than `lastSyncTime`.

### What did you expect to happen?

The pod phase transition should be as fast as GenericPLEG. It would be better to set `globalCacheUpdatePeriod` to 1 second.

### How can we reproduce it (as minimally and precisely as possible)?
This issue can be observed in the `pull-kubernetes-node-crio-cgrpv1-evented-pleg-e2e` job as described in https://github.com/kubernetes/kubernetes/pull/124297#issuecomment-2340279198:
```
E2eNode Suite: [It] [sig-node] [NodeFeature:SidecarContainers] Containers Lifecycle [It] should not hang in termination if terminated during initialization [sig-node, NodeFeature:SidecarContainers]
{ failed [FAILED] should delete in < 5 seconds, took 10.071795
Expected
    <float64>: 10.071794756
to be <
    <int64>: 5
In [It] at: k8s.io/kubernetes/test/e2e_node/container_lifecycle_test.go:3470 @ 09/10/24 08:54:31.819
}
```

This can be also reproduced manually as follows:

Build kubernetes locally with applying PR #124297 and run with enabling `EventedPLEG` feature gate.

Use this simple-pod.yaml
```
apiVersion: v1
kind: Pod
metadata:
  labels:
	run: simple-pod
  name: simple-pod
spec:
  containers:
  - command:
	- sh
	- -c
	- trap "exit 0" SIGTERM; while true; do sleep 1; done
	image: busybox
	name: simple-container
```

Run the command:
```
$ kubectl create -f simple-pod.yaml; kubectl get pod simple-pod -w & kubectl wait --for=jsonpath='{.status.phase}'=Running pod simple-pod; sleep 1; kubectl delete pod simple-pod; kill $!
```

This is the result I tried the command ten times:
<details>

```
$ for i in `seq 10`; do kubectl create -f simple-pod.yaml; kubectl get pod simple-pod -w & kubectl wait --for=jsonpath='{.status.phase}'=Running pod simple-pod; sleep 1; kubectl delete pod simple-pod; kill $!; done
pod/simple-pod created
[1] 17875
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	12s
simple-pod   0/1 	Terminating     	0      	17s
simple-pod   0/1 	Terminating     	0      	17s
simple-pod   0/1 	Terminating     	0      	17s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 18248
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	6s
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 18583
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	6s
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 19057
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
simple-pod   1/1 	Terminating     	0      	6s
pod "simple-pod" deleted
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 19386
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	6s
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 19718
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	6s
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 20052
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	6s
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 20586
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	6s
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 20914
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	6s
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 21294
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	5s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	6s
simple-pod   0/1 	Terminating     	0      	15s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
simple-pod   0/1 	Terminating     	0      	20s
```

</details>

This is the result when `EventedPLEG` is disabled:

<details>

```
$ for i in `seq 10`; do kubectl create -f simple-pod.yaml; kubectl get pod simple-pod -w & kubectl wait --for=jsonpath='{.status.phase}'=Running pod simple-pod; sleep 1; kubectl delete pod simple-pod; kill $!; done
pod/simple-pod created
[1] 34236
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 34506
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 34820
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
pod/simple-pod condition met
simple-pod   1/1 	Running         	0      	2s
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 35084
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 35373
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 35640
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 35900
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 36173
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 36430
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
pod/simple-pod created
[1]+  Exit 1              	kubectl get pod simple-pod -w
[1] 36694
NAME     	READY   STATUS          	RESTARTS   AGE
simple-pod   0/1 	ContainerCreating   0      	0s
simple-pod   1/1 	Running         	0      	2s
pod/simple-pod condition met
pod "simple-pod" deleted
simple-pod   1/1 	Terminating     	0      	3s
simple-pod   0/1 	Terminating     	0      	4s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
simple-pod   0/1 	Terminating     	0      	5s
```

</details>


### Anything else we need to know?

_No response_

### Kubernetes version

master + PR #124297

<details>

```console
$ kubectl version
# paste output here
Client Version: v1.28.2
Kustomize Version: v5.0.4-0.20230601165947-6ce0bf390ce3
Server Version: v1.31.0-alpha.0.582+8ec29a96e91e40
WARNING: version difference between client (1.28) and server (1.31) exceeds the supported minor version skew of +/-1
```

</details>


### Cloud provider

<details>
None
</details>


### OS version

<details>

```console
# On Linux:
$ cat /etc/os-release
# paste output here
$ uname -a
# paste output here

# On Windows:
C:\> wmic os get Caption, Version, BuildNumber, OSArchitecture
# paste output here
```

</details>


### Install tools

<details>

</details>


### Container runtime (CRI) and version (if applicable)

<details>

</details>


### Related plugins (CNI, CSI, ...) and versions (if applicable)

<details>

</details>