1.45.0 sometimes fails to remove taint

[dpiddock]

/kind bug

What happened?
We have upgraded some clusters to EKS 1.33 and ebs-csi v1.45.0-eksbuild.2 from EKS 1.32 and ebs-csi v1.42.0-eksbuild.1. We have seen a small number of nodes get stuck with the ebs-csi taint not getting cleared. This leaves the node in a state where workload pods will not get scheduled and Karpenter will not remove the node as it has not finished initializing yet.

What you expected to happen?
Taint to be removed.

How to reproduce it (as minimally and precisely as possible)?
Unfortunately this is a rare race condition that we can't reproduce reliably.

Anything else we need to know?:
Looking through the audit logs it looks like the ebs-csi pod is not refreshing the node's current taints when the update request fails. It keeps retrying with the same outdated state.

Sample from CloudWatch logs:
Taints are:

responseObject.spec.taints.0 {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
responseObject.spec.taints.1 {"key":"efs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
responseObject.spec.taints.2 {"key":"node.kubernetes.io/not-ready","effect":"NoExecute","timeAdded":"2025-07-22T12:17:19Z"}

node-controller removes a taint leaving just the csi controllers:

@timestamp                   1753186659667
requestObject.spec.taints.0  {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.spec.taints.1  {"key":"efs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestReceivedTimestamp     2025-07-22T12:17:39.545267Z
responseObject.spec.taints.0 {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
responseObject.spec.taints.1 {"key":"efs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
verb                         patch

ebs-csi fails to update:

@timestamp               1753186660233
requestObject.0.op       test
requestObject.0.path     /spec/taints
requestObject.value.0    {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.value.1    {"key":"efs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.value.2    {"key":"node.kubernetes.io/not-ready","effect":"NoExecute","timeAdded":"2025-07-22T12:17:19Z"}
requestObject.1.op       replace
requestObject.1.path     /spec/taints
requestObject.value.0    {"key":"efs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.value.1    {"key":"node.kubernetes.io/not-ready","effect":"NoExecute","timeAdded":"2025-07-22T12:17:19Z"}
requestReceivedTimestamp 2025-07-22T12:17:40.096491Z
responseObject.code      422
responseObject.kind      Status
responseObject.message   the server rejected our request due to an error in our request
responseObject.reason    Invalid
responseObject.status    Failure
responseStatus.code      422
responseStatus.message   the server rejected our request due to an error in our request
responseStatus.reason    Invalid
responseStatus.status    FailurerequestObject.value.0  {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
verb                     patch

Keeps trying with same input and result:

@timestamp 1753186660483
requestReceivedTimestamp 2025-07-22T12:17:40.194728Z

@timestamp 1753186663240
requestReceivedTimestamp 2025-07-22T12:17:43.202173Z

@timestamp 1753186663240
requestReceivedTimestamp 2025-07-22T12:17:43.104818Z

@timestamp 1753186667752
requestReceivedTimestamp 2025-07-22T12:17:47.711254Z

@timestamp 1753186667752
requestReceivedTimestamp 2025-07-22T12:17:47.614086Z

@timestamp 1753186674520
requestReceivedTimestamp 2025-07-22T12:17:54.470557Z

@timestamp 1753186674520
requestReceivedTimestamp 2025-07-22T12:17:54.379558Z

@timestamp 1753186674520
requestReceivedTimestamp 2025-07-22T12:17:54.372631Z

@timestamp 1753186676525
requestReceivedTimestamp 2025-07-22T12:17:56.387603Z

efs-csi removes its taint:

@timestamp                   1753186678278
requestObject.0.op           test
requestObject.0.path         /spec/taints
requestObject.0.value.0      {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.0.value.1      {"key":"efs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.1.op           replace
requestObject.1.path         /spec/taints
requestObject.1.value.0      {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestReceivedTimestamp     2025-07-22T12:17:58.113754Z
responseObject.spec.taints.0 {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
verb                         patch

ebs-csi continues trying to replace old taints:

@timestamp               1753186679531
requestObject.0.op       test
requestObject.0.path     /spec/taints
requestObject.value.0    {"key":"ebs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.value.1    {"key":"efs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.value.2    {"key":"node.kubernetes.io/not-ready","effect":"NoExecute","timeAdded":"2025-07-22T12:17:19Z"}
requestObject.1.op       replace
requestObject.1.path     /spec/taints
requestObject.value.0    {"key":"efs.csi.aws.com/agent-not-ready","effect":"NoExecute"}
requestObject.value.1    {"key":"node.kubernetes.io/not-ready","effect":"NoExecute","timeAdded":"2025-07-22T12:17:19Z"}
requestReceivedTimestamp 2025-07-22T12:17:59.395297Z
responseObject.code      422
responseObject.kind      Status
responseObject.message   the server rejected our request due to an error in our request
responseObject.reason    Invalid
responseObject.status    Failure
responseStatus.code      422
responseStatus.message   the server rejected our request due to an error in our request
responseStatus.reason    Invalid
responseStatus.status    Failure

The condition does not resolve itself. We've seen nodes that are 4d+ old.

Environment

• Kubernetes version (use kubectl version): v1.33.1-eks-595af52
• Driver version: v1.45.0-eksbuild.2

[mdzraf]

Hello @dpiddock thank you for reporting this, we will look into it and provide updates on the issue.

[mdzraf]

@dpiddock We are trying to reproduce this issue, in the meantime, if you have any more information that could be useful such as the node pod logs during the event, please provide them.

[dpiddock]

Here the logs from a couple of the failed ebs-csi pods

ebs.txt
ebs2.txt

[ConnorJC3]

/reopen

Hi @dpiddock - it's been extremely difficult to consistently reproduce and debug this, but we tried in #2588 to make the taint removal mechanism significantly more robust. When you are able can you upgrade to EBS CSI Driver v1.47.0 or later and let us know if that fixes the issue for you? Thanks!

[k8s-ci-robot]

@ConnorJC3: Reopened this issue.

In response to this:

/reopen

Hi @dpiddock - it's been extremely difficult to consistently reproduce and debug this, but we tried in #2588 to make the taint removal mechanism significantly more robust. When you are able can you upgrade to EBS CSI Driver v1.47.0 or later and let us know if that fixes the issue for you? Thanks!

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-sigs/prow repository.

[guntiskarulis]

Hi @ConnorJC3. In our environment (EKS 1.33) we didn't see any issues with taint removal before, but now, after we upgraded ebs csi driver to v1.48 we started to see a lot of these errors:

E0923 02:41:51.908901 1 node.go:950] "Failed to get node for last chance" err="client rate limiter Wait returned an error: context deadline exceeded" node="xxx"

UPDATE:
Wanted to add bit more information here. We see this context deadline exceeded error only once after 10 minutes on the new node. Could this be because in that lastChanceNode call we're reusing ctx which is already canceled?

[dpiddock]

Hi @ConnorJC3. We've been running v1.48.0-eksbuild.1 on some of our EKS 1.33 clusters since 4th September and haven't seen a repeat of the issue. The fix appears to be working for us.

The log output is a bit weird though. It goes into a loop of "successfully removed" and "failed to remove" until finally detected as successful. For example:

I0923 09:18:33.204682       1 reflector.go:430] "Caches populated" type="*v1.Node" reflector="/gomodcache/k8s.io/client-go@v0.33.4/tools/cache/reflector.go:285"
E0923 09:18:33.208345       1 node.go:896] "Failed to remove agent-not-ready taint, retrying" err="isAllocatableSet: driver not found on node ip-10-251-153-123.eu-central-1.compute.internal" node="ip-10-251-153-123.eu-central-1.compute.internal"
E0923 09:18:35.214975       1 node.go:896] "Failed to remove agent-not-ready taint, retrying" err="isAllocatableSet: driver not found on node ip-10-251-153-123.eu-central-1.compute.internal" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:38.220275       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
E0923 09:18:38.225358       1 node.go:896] "Failed to remove agent-not-ready taint, retrying" err="the server rejected our request due to an error in our request" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:42.735153       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
I0923 09:18:42.748197       1 node.go:1017] "Removed taint(s) from local node" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:42.748218       1 node.go:907] "Successfully removed agent-not-ready taint" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:42.751536       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
E0923 09:18:42.755693       1 node.go:896] "Failed to remove agent-not-ready taint, retrying" err="the server rejected our request due to an error in our request" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:44.776355       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
I0923 09:18:44.776383       1 node.go:907] "Successfully removed agent-not-ready taint" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:44.779669       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
E0923 09:18:44.783468       1 node.go:896] "Failed to remove agent-not-ready taint, retrying" err="the server rejected our request due to an error in our request" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:46.795358       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
I0923 09:18:46.795392       1 node.go:907] "Successfully removed agent-not-ready taint" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:46.799967       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
E0923 09:18:46.810444       1 node.go:896] "Failed to remove agent-not-ready taint, retrying" err="the server rejected our request due to an error in our request" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:48.818788       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
I0923 09:18:48.818812       1 node.go:907] "Successfully removed agent-not-ready taint" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:48.824736       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
E0923 09:18:48.829835       1 node.go:896] "Failed to remove agent-not-ready taint, retrying" err="the server rejected our request due to an error in our request" node="ip-10-251-153-123.eu-central-1.compute.internal"
I0923 09:18:50.839401       1 node.go:1030] "CSINode Allocatable value is set" nodeName="ip-10-251-153-123.eu-central-1.compute.internal" count=26
I0923 09:18:50.839426       1 node.go:907] "Successfully removed agent-not-ready taint" node="ip-10-251-153-123.eu-central-1.compute.internal"

[alex-berger]

Technically, the fix from #2588 seems to work, but now there is always the below error message in the logs, which I assume is a (harmless but annoying) bug introduced by the fix:

E1001 10:51:12.341385       1 node.go:936] "Failed to get node for last chance" err="client rate limiter Wait returned an error: context deadline exceeded" node="ip-10-176-22-75.eu-central-1.compute.internal"

I guess this is caused because the context ctx is already cancelled at that point as its 10 minute timeout expired.

lastChanceNode, err := clientset.CoreV1().Nodes().Get(ctx, nodeName, metav1.GetOptions{})

Which probably should look more like this, using a dedicated Context instance which is still valid.

finalCtx, finalCancel := context.WithTimeout(context.Background(), 30*time.Second)
defer finalCancel()
lastChanceNode, err := clientset.CoreV1().Nodes().Get(finalCtx, nodeName, metav1.GetOptions{})

Full log:

I1001 10:41:12.141615       1 main.go:154] "Initializing metadata"
I1001 10:41:12.141697       1 metadata.go:75] "Attempting to retrieve instance metadata from Kubernetes API"
I1001 10:41:12.141870       1 envvar.go:172] "Feature gate default state" feature="InformerResourceVersion" enabled=false
I1001 10:41:12.141888       1 envvar.go:172] "Feature gate default state" feature="WatchListClient" enabled=false
I1001 10:41:12.141892       1 envvar.go:172] "Feature gate default state" feature="ClientsAllowCBOR" enabled=false
I1001 10:41:12.141896       1 envvar.go:172] "Feature gate default state" feature="ClientsPreferCBOR" enabled=false
I1001 10:41:12.141900       1 envvar.go:172] "Feature gate default state" feature="InOrderInformers" enabled=true
I1001 10:41:12.239312       1 metadata.go:78] "Retrieved metadata from Kubernetes"
I1001 10:41:12.239864       1 driver.go:72] "Driver Information" Driver="ebs.csi.aws.com" Version="v1.49.0"
I1001 10:41:12.241344       1 reflector.go:436] "Caches populated" type="*v1.Node" reflector="/gomodcache/k8s.io/client-go@v0.34.1/tools/cache/reflector.go:290"
E1001 10:41:12.245551       1 node.go:882] "Failed to remove agent-not-ready taint, retrying" err="isAllocatableSet: driver not found on node ip-10-176-22-75.eu-central-1.compute.internal" node="ip-10-176-22-75.eu-central-1.compute.internal"
I1001 10:41:14.254164       1 node.go:1016] "CSINode Allocatable value is set" nodeName="ip-10-176-22-75.eu-central-1.compute.internal" count=27
I1001 10:41:14.272809       1 node.go:1003] "Removed taint(s) from local node" node="ip-10-176-22-75.eu-central-1.compute.internal"
I1001 10:41:14.272835       1 node.go:893] "Successfully removed agent-not-ready taint" node="ip-10-176-22-75.eu-central-1.compute.internal"
I1001 10:41:14.276510       1 node.go:1016] "CSINode Allocatable value is set" nodeName="ip-10-176-22-75.eu-central-1.compute.internal" count=27
E1001 10:41:14.285342       1 node.go:882] "Failed to remove agent-not-ready taint, retrying" err="the server rejected our request due to an error in our request" node="ip-10-176-22-75.eu-central-1.compute.internal"
I1001 10:41:16.304596       1 node.go:1016] "CSINode Allocatable value is set" nodeName="ip-10-176-22-75.eu-central-1.compute.internal" count=27
I1001 10:41:16.304622       1 node.go:893] "Successfully removed agent-not-ready taint" node="ip-10-176-22-75.eu-central-1.compute.internal"
I1001 10:41:24.940172       1 mount_linux.go:285] Detected OS without systemd
I1001 10:41:25.041320       1 node.go:284] "Volume needs resizing" source="/dev/nvme2n1"
I1001 10:41:25.044266       1 resizefs_linux.go:74] Device /dev/nvme2n1 resized successfully
I1001 10:43:47.570789       1 node.go:284] "Volume needs resizing" source="/dev/nvme3n1"
I1001 10:43:47.640502       1 resizefs_linux.go:74] Device /dev/nvme3n1 resized successfully
E1001 10:51:12.341385       1 node.go:936] "Failed to get node for last chance" err="client rate limiter Wait returned an error: context deadline exceeded" node="ip-10-176-22-75.eu-central-1.compute.internal"

[ConnorJC3]

Cut #2699 to fix the issue with the last try attempt. It also removes or increases the verbosity of some unnecessarily spammy log messages.

The repeated failures @dpiddock is seeing is likely the stale updates coming in from the informer - we generally trust the data from the informer, but our new release includes a fallback mechanism for when the informer data is wrong or out of date.

I'm not exactly sure what is wrong with your cluster as I was never able to reproduce the same situation, but I strongly suspect the api-server is returning stale or old data to watchers, and sometimes skipping the newest data. This would cause our previous implementation to never update the taint, but our new implementation proactively re-fetches the Node object if the update fails.