记录一次排查UnexpectedAdmissionError问题的过程

1. 问题

环境

3master节点+N个GPU节点

kubelet版本：v1.19.4

kubernetes版本：v1.19.4

生产环境K8S集群，莫名其妙的出现大量UnexpectedAdmissionError状态的Pod，导致部分任务执行异常，出现这种情况时，节点的资源是足以支持运行一个GPU Pod的。

报的错误：

Allocate failed due to requested number of devices unavailable for nvidia.com/gpu. Requested: 1, Available: 0, which is unexpected

因为Pod的调度都是指定了spec.nodeName属性的，所以跳过了Pending状态强制进行调度，在资源不足的情况下，就出现了UnexpectedAdmissionError异常。

image-20231207095349410

2.排查过程

确定节点资源是否正常

 kubectl describe node <node-name>

image-20231207095740526

通过describe命令可以看到节点的GPU卡是正常的，然后可以去节点上通过nvidia-dcgm，确定GPU设备是否健康

nvidia-dcgm：nvidia官网

在确定节点和GPU设备都是没问题的情况下，那么开始排查出现问题的原因

通过查看日志和源码，可以定位到日志是在manager.go#devicesToAllocate方法的698行出现

	// resource=nvidia.com/gpu
	// Gets Devices in use.
	devicesInUse := m.allocatedDevices[resource]
	// Gets Available devices.
	available := m.healthyDevices[resource].Difference(devicesInUse)
	if available.Len() < needed {
		return nil, fmt.Errorf("requested number of devices unavailable for %s. Requested: %d, Available: %d", resource, needed, available.Len())
	}

也就是，从健康的GPU集合中去除了已使用的GPU后，可用GPU数量少于所需要的数量，但是通过上面的排查，在创建的Pod.cm.resource.limit:nvidia.com/gpu=1的情况下，理论上应该是成功的，这里出现了报错，那么肯定是GPU卡被占用了。

查看kubelet日志，定位具体问题，日志位于/var/log/messages文件，由于kubelet默认日志级别为--v=2，这里需要将其更改为--v=4

查看是否有/etc/kubernetes/kubelet.env文件，如果有，直接更改KUBE_LOG_LEVEL配置

KUBE_LOGTOSTDERR="--logtostderr=true"
KUBE_LOG_LEVEL="--v=4"

如果没有，则修改/usr/lib/systemd/system/kubelet.service.d/10-kubeadm.conf文件

添加Environment

Environment="KUBE_LOGTOSTDERR=--logtostderr=true"
Environment="KUBE_LOG_LEVEL=--v=4"

修改ExecStart命令，在参数位追加$KUBE_LOGTOSTDERR $KUBE_LOG_LEVEL

ExecStart=/usr/bin/kubelet $KUBE_LOGTOSTDERR $KUBE_LOG_LEVEL $KUBELET_KUBECONFIG_ARGS $KUBELET_CONFIG_ARGS $KUBELET_KUBEADM_ARGS $KUBELET_EXTRA_ARGS

修改后需要重启kubelet

systemctl daemon-reload && systemctl restart kubelet

通过grep命令查看关键日志

grep "package-instance-42895-test-4461" messages

从日志中发现，kubelet监听到了两次创建同一个Pod的事件，也就是为一个Job创建了两个Pod

但是Job的配置都是为1

spec:
  completions: 1
  backoffLimit: 0
  parallelism: 1

image-20231207102252049

在这样的配置下，应该只有一次创建Pod的事件才对。

再分别查看两次Pod的资源分配日志

通过less messages命令查看详细的日志过程

image-20231207102820350

从日志中可以看出，第一个Pod分配GPU资源是成功的

而在第二个Pod分配GPU资源时，就提示分配失败

image-20231207102934592

至此问题就定位到了，是因为kubelet本应只创建一个Pod，但是确监听到了多次创建Pod的事件。

从这个情况来看，应当所有的任务都失败才对，但只有小部分任务失败了，继续查看日志

image-20231207103436250

在下面的日志可以看到，kubelet随后就监听到了DELETE事件，删除了一个Pod，虽然在这个日志中删除的是创建失败的Pod

但是多观察几个Pod就会发现，删除完全的随机的，并不是根据状态来的，所以就会出现部分任务失败，但是大部分任务都成功的情况。

从上面的排查过程来看，kubelete、node、gpu device都是没有问题的，那么，继续往上排查scheduler

同样的，scheduler的日志级别默认也是--v=2，这里也需要改成--v=4，修改kube-scheduler.yaml文件

vim /etc/kubernetes/manifests/kube-scheduler.yaml

在command中追加一行--v=4

spec:
  containers:
  - command:
    - kube-scheduler
    - --authentication-kubeconfig=/etc/kubernetes/scheduler.conf
    - --authorization-kubeconfig=/etc/kubernetes/scheduler.conf
    - --bind-address=0.0.0.0
    - --kubeconfig=/etc/kubernetes/scheduler.conf
    - --leader-elect=false
    - --leader-elect-lease-duration=15s
    - --leader-elect-renew-deadline=10s
    - --port=0
    - --v=4

更改文件后保存，等待scheduler自动重建。注意重建后日志会清空，所以需要等待下次调度再次重新进行问题排查

然后通过kubectl logs命令，查看三个scheduler的调度日志

kubectl logs -n kube-system kube-scheduler-master-1| grep package-instance-42895-test-4461

kubectl logs -n kube-system kube-scheduler-master-2| grep package-instance-42895-test-4461

kubectl logs -n kube-system kube-scheduler-master-3| grep package-instance-42895-test-4461

[root@master-1 ~]# kubectl logs -n kube-system kube-scheduler-master-1| grep package-instance-42895-test-4461
I1206 03:23:08.641125       1 eventhandlers.go:225] add event for scheduled pod default/package-instance-42895-test-4461-xxp5t
I1206 03:23:08.641463       1 eventhandlers.go:225] add event for scheduled pod default/package-instance-42895-test-4461-72hdl
I1206 03:23:08.866294       1 eventhandlers.go:283] delete event for scheduled pod default/package-instance-42895-test-4461-72hdl

[root@master-1 ~]# kubectl logs -n kube-system kube-scheduler-master-2| grep package-instance-42895-test-4461
I1206 03:23:08.641125       1 eventhandlers.go:225] add event for scheduled pod default/package-instance-42895-test-4461-xxp5t
I1206 03:23:08.641463       1 eventhandlers.go:225] add event for scheduled pod default/package-instance-42895-test-4461-72hdl
I1206 03:23:08.866294       1 eventhandlers.go:283] delete event for scheduled pod default/package-instance-42895-test-4461-72hdl

[root@master-1 ~]# kubectl logs -n kube-system kube-scheduler-master-3| grep package-instance-42895-test-4461

从上面的日志可以看到，Pod确实被调度了两次，但是，schduler只是负责调度Pod，并不会控制Pod创建的数量。

而且，理论上，应该只有一个leader级别的schduler处于工作状态，其他两个schduler，应当是处于睡眠状态，不进行工作才对，也就说，其他的schduler不应该监听到调度事件。

虽然问题不在此，但是从这里可以发现schduler的部署是有问题的，查看schduler配置

spec:
  containers:
  - command:
    - kube-scheduler
    - --authentication-kubeconfig=/etc/kubernetes/scheduler.conf
    - --authorization-kubeconfig=/etc/kubernetes/scheduler.conf
    - --bind-address=0.0.0.0
    - --kubeconfig=/etc/kubernetes/scheduler.conf
    - --leader-elect=false
    - --leader-elect-lease-duration=15s
    - --leader-elect-renew-deadline=10s
    - --port=0
    - --v=4

在检查了三个节点的schduler配置后，发现有一个节点的schduler配置中，--leader-elect被设置成了fasle

Kubernetes的调度器可以使用leader选举来确保只有一个实例处于活跃状态，负责决策和分配Pod。一旦调度器的活跃实例失效，其他备用实例可以进行leader选举，确保集群的Pod能够被适当地调度到可用的节点上。

同样，如果多个调度器实例都设置为--leader-elect=false，它们将尝试同时管理Pod的调度决策，可能会导致混乱、资源冲突以及不一致的状态。

在这可以确定是--leader-elect=false导致的出现了多个leader级的schduler，将此配置更改为--leader-elect=true。

等待schudler重建，修复了schudler多leader的问题，但是，Pod重复调度的问题依旧没有解决，查看Pod调度调度流程

image-20231207110614916

从流程图上可以看出，创建Pod的请求，是由Job Controller发出的，在kubernetes中有很多的控制器，例如

Job Controller、Deployment Controller，这些控制器由控制平面进行管理kube-controller-manger。

结合上面schduler的可以得出结论。是在Job Controller中，发出了两次创建Pod的请求，而kube-controller-manger集群跟schduler集群一样，理论上应该只有一个leader级别的处于工作中的状态，其他两个都应该处于休眠状态。但是这里发起了两次创建请求，显然是有一个以上的leader级的kube-controller-manger，通过查看配置文件，问题跟schduler是一样的

YAML文件路径/etc/kubernetes/manifests/kube-controller-manager.yaml

有一个节点的YAML文件中--leader-elect=false，这个配置也被设置为了false，导致的出现了多个ledaer级的控制平面，从而导致Pod被多次创建。

验证方式也是同样的，通过kubectl logs命令，查看三个kube-controller-manager的监听日志，发现有两个控制平面监听到了Create Job事件，从而导致的这次问题。

kubectl logs -n kube-system  kube-controller-manager-master-1 |grep package-instance-42895-test-4461

3. 解决方案

通过修改/etc/kubernetes/manifests/kube-scheduler.yaml和/etc/kubernetes/manifests/kube-controller-manager.yaml两个YAML文件中的--leader-elect配置，将其修改为true，即可解决问题。

--leader-elect=false
# kubernetes # java # 容器
Logo
云原生开发者技术专区邀请您加入

一起探索未来云端世界的核心，云原生技术专区带您领略创新、高效和可扩展的云计算解决方案，引领您在数字化时代的成功之路。

更多推荐

cover

猫头虎分享：鸿蒙生态带给开发者的全新机遇！轻松实现按需加载与多端适配，开发效率翻倍

avatar 云原生技术专区
cover

显示器不亮？解决“显示器不支持当前的输入时序，请将输入时序更改为 1920x1080, 60Hz”的终极指南

avatar 云原生技术专区
cover

如何解决ffmpeg安装报错ERROR: You have requested merging of multiple formats but ffmpeg is not installed

avatar 云原生技术专区