VPC CNI stuck in crash loop without insights
duxing opened this issue · 11 comments
What happened:
I'm working on testing autoscaling for my EKS cluster (1.29) and karpenter
is frequently scaling nodes up and down during my test.
At a certain point, all newly launched nodes stuck in NotReady
due to VPC CNI pod stuck in crash loop.
The symptom is very similar to hitting EC2/ENI API rate limit, however, I can't find out useful logs / metrics from the client (VPC CNI pod) to help me confirm/diagnose, despite AWS_VPC_K8S_CNI_LOGLEVEL
is set to DEBUG
(AWS_VPC_K8S_PLUGIN_LOG_LEVEL
is also DEBUG
if it matters)
The version i'm using is v1.18.1-eksbuild.3
(the EKS optimized addon) and the logs are attached below.
Attach logs
unable to run sudo bash /opt/cni/bin/aws-cni-support.sh
: the image 602401143452.dkr.ecr.us-east-1.amazonaws.com/amazon-k8s-cni:v1.18.1-eksbuild.3
seems to be distroless
logs from kubectl logs -f ...
:
successfully launched aws-node
pod (AWS_VPC_K8S_CNI_LOGLEVEL=DEBUG
):
Installed /host/opt/cni/bin/aws-cni
Installed /host/opt/cni/bin/egress-cni
time="2024-06-04T23:27:31Z" level=info msg="Starting IPAM daemon... "
time="2024-06-04T23:27:31Z" level=info msg="Checking for IPAM connectivity... "
time="2024-06-04T23:27:33Z" level=info msg="Copying config file... "
time="2024-06-04T23:27:33Z" level=info msg="Successfully copied CNI plugin binary and config file."
stuck aws-node
pod (also AWS_VPC_K8S_CNI_LOGLEVEL=DEBUG
):
Installed /host/opt/cni/bin/aws-cni
Installed /host/opt/cni/bin/egress-cni
time="2024-06-05T03:40:00Z" level=info msg="Starting IPAM daemon... "
time="2024-06-05T03:40:00Z" level=info msg="Checking for IPAM connectivity... "
// stuck here indefinitely until container is restarted
What you expected to happen:
with AWS_VPC_K8S_CNI_LOGLEVEL=DEBUG
, logs should be more verbose, spitting out information about what the process is doing.
whatever error/exception that caused initialization failure should be surfaced to the log stream under pretty much any log level (should be ERROR log level for these entries)
if there are exponential backoff retry for 429 responses, it needs to be surfaced during verbose mode (debug log level)
How to reproduce it (as minimally and precisely as possible):
- launch
EKS@1.29
and install VPC CNIv1.18.1-eksbuild.3
from EKS addons - frequently launch and terminate (after nodes become
ready
) nodes in batches (batch of 15 instances, every 10mins) - wait until nodes are unable to become healthy due to
aws-node
pod stuck in crash loop
Anything else we need to know?:
Environment:
- Kubernetes version (use
kubectl version
):
Client Version: v1.29.3
Kustomize Version: v5.0.4-0.20230601165947-6ce0bf390ce3
Server Version: v1.29.4-eks-036c24b
- CNI Version:
v1.18.1-eksbuild.3
- OS (e.g:
cat /etc/os-release
): - Kernel (e.g.
uname -a
):
sudo bash /opt/cni/bin/aws-cni-support.sh
should be run from the node where you are observing the crash loop. Can you also see what the ipamd.log and plugin.log say in the same node. They are located in /var/log/aws-routed-eni/ipamd.log and /var/log/aws-routed-eni/plugin.log
@orsenthil thx for the clarification.
I missed the window when this issue can be consistently reproduced (I suspect it has something to do with AWS API rate limiting) and I'm unable to reproduce this right now, but I'll check if I can find the logs from the affected nodes from that time.
update:
unable to do that. the daemonset pod failed initialization due to VPC CNI stuck in crash loop. I may have to reproduce this again to see the logs
however, I did get your point about the log verbosity setting is affecting the /var/log/aws-routed-eni/ipamd.log
file, and I think this issue can be closed.
would you recommend setting AWS_VPC_K8S_CNI_LOG_FILE
to be /dev/stdout
to make the logs available for kubectl logs -f
?
I was to reproduce this on an EKS node that I have SSH access to and the results have been sent to k8s-awscni-triage@amazon.com
after going through ipamd.log
and other log files under /var/log/aws-routed-eni/
, I couldn't find any useful log lines that can help me confirm if this is a rate limit issue or identify what's causing the failure.
as this comment is written, the node has been in this state for 19m (together with many nodes that are stuck for 40mins):
kubectl get nodes --sort-by=.metadata.creationTimestamp
...
ip-10-231-76-39.ec2.internal Ready <none> 33h v1.29.0-eks-5e0fdde
ip-10-231-75-201.ec2.internal Ready <none> 159m v1.29.0-eks-5e0fdde
ip-10-231-107-179.ec2.internal NotReady <none> 37m v1.29.0-eks-5e0fdde
...
ip-10-231-87-255.ec2.internal NotReady <none> 19m v1.29.0-eks-5e0fdde
if it helps:
I managed to launch 1 node 159ms ago (pool is homogenous): after this issue is reported but before this current response.
I guess the "issue" I have is: the ipamd
log or kubectl logs -f
should provide some insights on why this particular failure is happening
This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days
update on this:
I don't think this issue is fixable and as suggested, configuring kube-proxy
to run in ipvs mode in a large cluster would alleviate this issue.
however, it would be helpful if vpc-cni
can throw a log when this happens so that this is more self-contained. I could not figure out why when I go through the verbose log of vpc-cni
, it wasn't until I cross check the timestamp of kube-proxy
logs from the same node did I realize why this happened.