Loading...
墨滴

IT明哥

2021/10/13  阅读:37  主题:默认主题

Kubernetes 应用问题的通用排查思路 - 大数据从业者之 Kubernetes 必知必会

Kubernetes 应用问题的通用排查思路 - 大数据从业者之 Kubernetes 必知必会

大家好,我是明哥!

1 技术趋势大背景

我们知道,大数据进一步发展的一个趋势,就是大数据和云计算进一步融合(包括在底层更加青睐存储计算分离的架构,在底层更加青睐对象存储),在部署架构上支持混合云和多云场景,拥抱云计算走向云原生化。

对应到底层具体技术堆栈上,体现在各个主流大数据平台和底层的大数据组件,纷纷开始支持以 Kubernetes 和 Docker 为代表的容器系列技术栈。

所以大数据从业者,需要不断扩展自己的技能包,掌握 Kubernetes 和 Docker 的基础知识和常见命令,才能在排查大数据相关问题时不至于捉襟见肘,因技能储备短缺,无从下手。

在此分享一个大数据平台中 docker 容器相关故障的排查案列,并介绍下此类问题的背后知识和排查思路,以飨读者,大家共勉!

2 问题现象

星环大数据平台 TDH 中, zookeeper 服务无法正常启动。 我们知道 TDH 中,各个服务其实是在 k8s 的管控下运行于 docker 容器中,通过 kubectl get pods -owide |grep -i zoo 可以发现,对应的 pod 的状态是CrashLoopBackOff,如下图所示:

pod-CrashLoopBackOff
pod-CrashLoopBackOff

3 背后知识:什么是 CrashLoopBackOff?

某个 pod 处于 CrashloopBackOff, 意味着该 pod 中的容器被启动了,然后崩溃了,接下来又被自动启动了,但又崩溃了,如此周而复始,陷入了(starting, crashing, starting,crashing)的循坏.

注意:pod 中的容器之所以会被自动重启,其实是通过 PodSpec 中的 restartPolicy 指定的,该配置项默认是 Always,即失败后会自动重启:

  • A PodSpec has a restartPolicy field with possible values Always, OnFailure, and Never which applies to all containers in a pod, the default value is Always;
  • The restartPolicy only refers to restarts of the containers by the kubelet on the same node (so the restart count will reset if the pod is rescheduled in a different node).
  • Failed containers that are restarted by the kubelet are restarted with an exponential back-off delay (10s, 20s, 40s …) capped at five minutes, and is reset after ten minutes of successful execution.

4 背后知识:为什么会发生 CrashLoopBackOff 错误?

pod 的 CrashLoopBackOff 错误还是挺常见的,该错误可能会因为多种原因被触发,几个主要的上层原因有:

  • Kubernetes 集群部署有问题;
  • 该 pod 或 pod 底层的 container 的某些参数被配置错了;
  • 该 pod 内部的 container 中运行的应用程序,在多次重启运行时都一直处于失败状态;

5 背后知识:如何排查 pod 容器底层的应用程序的故障?

当 pod 容器底层的应用程序运行出现故障时,通用的排查思路,一般是:

  1. 步骤一:通过命令 kubectl describe pod xxx 获取 pod 详细信息
  2. 步骤二:通过命令 kubectl logs xxx 查看 pod 容器底层的应用程序的日志
  3. 步骤三:进一步获取并查看 pod 容器底层的应用程序的其它日志文件,深挖问题原因

有的小伙伴可能会有疑问,上述步骤二和步骤三都是查看 pod 容器底层的应用程序的日志,有什么区别呢?

其实步骤二和步骤三在底层查看的是应用程序的不同的日志文件,其底层细节跟 kubernetes 的日志机制,以及该 pod 底层的应用程序将日志写向何处有关:

  • kubectl logs 展示的是 pod 底层的 container 的标准输出 stdout 和标准错误 stderr 的日志;
  • 应用程序写到其它文件的日志,kubectl logs 展示不了,需要获取日志文件路径,并自行查看;
  • k8s 建议应用程序将日志写到 container 的标准输出 stdout 和标准错误 stderr;
  • 容器内的应用程序可以将日志直接写到 container 的标准输出 stdout 和标准错误 stderr;
  • 如果容器内的应用程序不能或不方便将日志直接写到 container 的标准输出 stdout 和标准错误 stderr,可以使用 sidecar 即边车模式,在应用程序的 container 所在的 pod 内部署另一个 sidecar container,该 sidecar container 负责读取应用程序的日志文件并输出到其标准输出 stdout 和标准错误 stderr 里;
  • k8s 在底层会通过运行在各个节点的 kubelet 来收集节点中所有 container 的 stdout 和 stderr 日志,并写到一个 kubelet 管理的本地文件中;
  • 用户执行 kubectl logs xx 命令时,该命令在底层会调用该 container 对应节点上的 kubelet 来检索其管理的本地日志文件,以获取日志;
  • 用户使用 kubectl log xxx 来检索应用程序日志,省去了用户登录 k8s 集群中对应节点查看对应日志的繁琐操作,提供了很大遍历;

ps. 我们这里讨论的是运行在 k8s 容器中的应用程序的日志,除了应用程序的日志,其实整个k8s 集群中还有很多系统组件的日志,如:docker,kubelet,kube-proxy,kube-apiserver,kube-scheduler,etcd等。

6 问题排查复盘

按照上述通用问题排查思路,我们复盘回顾下该 CrashLoopBackOff 问题的排查经过。

6.1:问题排查复盘:通过命令 kubeclt describe pod xxx 获取 pod 详细信息

该命令输出的部分截图如下,通过输出中 Events 部分,我们可以获取如下信息:该 pod 被成功地分配到了某个节点上,然后镜像拉取成功,然后 contaier 创建和启动成功,但随后 contaier 中程序运行失败,最后 pod 进入到了 BackOff 状态:

kubectl-describe-pod
kubectl-describe-pod

该命令的详细输出如下:

kubectl describe pod zookeeper-server-license-7fbfc544fc-h8nn9
Name:               zookeeper-server-license-7fbfc544fc-h8nn9
Namespace:          default
Priority:           0
PriorityClassName:  <none>
Node:               uf30-tdh3-regression/10.20.159.115
Start Time:         Mon, 11 Oct 2021 16:56:30 +0800
Labels:             name=zookeeper-server-license
                    pod-template-hash=3969710097
                    podConflictName=zookeeper-server-license
Annotations:        <none>
Status:             Running
IP:                 10.20.159.115
Controlled By:      ReplicaSet/zookeeper-server-license-7fbfc544fc
Containers:
  zookeeper-server-license:
    Container ID:  docker://0887c97ab185f1b004759e8c85b48631f511cb43088424190c3f27c715bb8414
    Image:         transwarp/zookeeper:transwarp-6.0.2-final
    Image ID:      docker-pullable://transwarp/zookeeper@sha256:19bf952dedc70a1d82ba9dd9217a2b7e34fc018561c2741d8f6065c0d87f8a10
    Port:          <none>
    Args:
      boot.sh
      LICENSE_NODE
    State:          Terminated
      Reason:       Error
      Exit Code:    1
      Started:      Mon, 11 Oct 2021 17:12:09 +0800
      Finished:     Mon, 11 Oct 2021 17:12:10 +0800
    Last State:     Terminated
      Reason:       Error
      Exit Code:    1
      Started:      Mon, 11 Oct 2021 17:07:07 +0800
      Finished:     Mon, 11 Oct 2021 17:07:08 +0800
    Ready:          False
    Restart Count:  8
    Environment:
      ZOOKEEPER_CONF_DIR:  /etc/license/conf
    Mounts:
      /etc/license/conf from conf (rw)
      /etc/localtime from timezone (rw)
      /etc/tos/conf from tos (rw)
      /etc/transwarp/conf from transwarphosts (rw)
      /usr/lib/transwarp/plugins from plugin (rw)
      /var/license from data (rw)
      /var/log/license/ from log (rw)
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-g42jt (ro)
      /vdir from mountbind (rw)
Conditions:
  Type           Status
  Initialized    True 
  Ready          False 
  PodScheduled   True 
Volumes:
  data:
    Type:          HostPath (bare host directory volume)
    Path:          /var/license
    HostPathType:  
  conf:
    Type:          HostPath (bare host directory volume)
    Path:          /etc/license/conf
    HostPathType:  
  log:
    Type:          HostPath (bare host directory volume)
    Path:          /var/log/license/
    HostPathType:  
  mountbind:
    Type:          HostPath (bare host directory volume)
    Path:          /transwarp/mounts/license
    HostPathType:  
  plugin:
    Type:          HostPath (bare host directory volume)
    Path:          /usr/lib/transwarp/plugins
    HostPathType:  
  timezone:
    Type:          HostPath (bare host directory volume)
    Path:          /etc/localtime
    HostPathType:  
  transwarphosts:
    Type:          HostPath (bare host directory volume)
    Path:          /etc/transwarp/conf
    HostPathType:  
  tos:
    Type:          HostPath (bare host directory volume)
    Path:          /etc/tos/conf
    HostPathType:  
  default-token-g42jt:
    Type:        Secret (a volume populated by a Secret)
    SecretName:  default-token-g42jt
    Optional:    false
QoS Class:       BestEffort
Node-Selectors:  zookeeper-server-license
=true
Tolerations:     node.kubernetes.io/not-ready:NoExecute for 300s
                 node.kubernetes.io/unreachable:NoExecute for 300s
Events:
  Type     Reason                 Age                 From                           Message
  ----     ------                 ----                ----                           -------
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "default-token-g42jt"
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "conf"
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "tos"
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "mountbind"
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "transwarphosts"
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "log"
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "plugin"
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "data"
  Normal   SuccessfulMountVolume  15m                 kubelet, uf30-tdh3-regression  MountVolume.SetUp succeeded for volume "timezone"
  Normal   Scheduled              15m                 default-scheduler              Successfully assigned zookeeper-server-license-7fbfc544fc-h8nn9 to uf30-tdh3-regression
  Normal   Pulled                 15m (x3 over 15m)   kubelet, uf30-tdh3-regression  Successfully pulled image "transwarp/zookeeper:transwarp-6.0.2-final"
  Normal   Created                15m (x3 over 15m)   kubelet, uf30-tdh3-regression  Created container
  Normal   Started                15m (x3 over 15m)   kubelet, uf30-tdh3-regression  Started container
  Normal   Pulling                15m (x4 over 15m)   kubelet, uf30-tdh3-regression  pulling image "transwarp/zookeeper:transwarp-6.0.2-final"
  Warning  BackOff                44s (x70 over 15m)  kubelet, uf30-tdh3-regression  Back-off restarting failed container

6.2 问题排查复盘:通过命令 kubectl logs xxx 查看 pod 容器底层的应用程序的日志

接下来我们尝试通过命令 kubectl logs xxx 查看 pod 容器底层的应用程序的日志,以期找到问题的原因,该命令的输出部分截图如下所示: kubectl logs xxx

如上图所见,不幸的是,该命令的输出,没有展示出问题的根本原因。

在底层日志机制上,应该是星环 tdh 中该 zk 应用没有将日志打印到标准输出 stdout 和标准错误 stderr, 所以 kubectl logs xxx 查看不到对应的日志。

我们需要进一步排查。

6.3 问题排查复盘:进一步获取并查看 pod 容器底层的应用程序的其它日志文件,深挖问题原因

进一步排查问题,我们首先需要获取 pod 容器底层的应用程序的其它日志文件的路径。

由于 tdh 是闭源的,我们查看不到应用程序的源码,在没有联络官方客户的情况下,我们可以通过命令 kubectl describe pod xxx 查看该 pod 挂载了哪些 volume,然后猜测并验证获得具体的日志文件的路劲给,(***排查问题就是要,大胆猜想,小心求证!***)

该命令输出的部分截图如下,我们看到其中挂载了路径 /var/log/license: pod-volume-mounts

接下来我们查看这些日志文件/var/log/license,尝试深挖问题原因,注意,该文件是本地文件系统的文件,需要登录到对应的节点上去查看,该日志文件部分关键截图如下: errors-in-log-file

通过日志,问题原因找到了:zk 底层存储在本地文件系统中的文件 /var/license/version-2/snapshot.70000007a 损坏了,所以无法启动:

2021-10-11 17:07:08,330 ERROR org.apache.zookeeper.server.persistence.Util: [myid:16] - [main:Util@239] - Last transaction was partial.
2021-10-11 17:07:08,331 ERROR org.apache.zookeeper.server.quorum.QuorumPeer: [myid:16] - [main:QuorumPeer@453] - Unable to load database on disk
java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392)

该日志文件详细内容如下:

tail -50 /var/log/license/zookeeper.log
2021-10-11 17:07:08,203 INFO  org.apache.zookeeper.server.DatadirCleanupManager: [myid:16] - [main:DatadirCleanupManager@101] - Purge task is not scheduled.
2021-10-11 17:07:08,212 INFO  org.apache.zookeeper.server.quorum.QuorumPeerMain: [myid:16] - [main:QuorumPeerMain@127] - Starting quorum peer
2021-10-11 17:07:08,221 INFO  org.apache.zookeeper.server.NIOServerCnxnFactory: [myid:16] - [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2291
2021-10-11 17:07:08,235 INFO  org.apache.zookeeper.server.quorum.QuorumPeer: [myid:16] - [main:QuorumPeer@913] - tickTime set to 9000
2021-10-11 17:07:08,235 INFO  org.apache.zookeeper.server.quorum.QuorumPeer: [myid:16] - [main:QuorumPeer@933] - minSessionTimeout set to -1
2021-10-11 17:07:08,235 INFO  org.apache.zookeeper.server.quorum.QuorumPeer: [myid:16] - [main:QuorumPeer@944] - maxSessionTimeout set to -1
2021-10-11 17:07:08,236 INFO  org.apache.zookeeper.server.quorum.QuorumPeer: [myid:16] - [main:QuorumPeer@959] - initLimit set to 10
2021-10-11 17:07:08,285 INFO  org.apache.zookeeper.server.persistence.FileSnap: [myid:16] - [main:FileSnap@83] - Reading snapshot /var/license/version-2/snapshot.70000007a
2021-10-11 17:07:08,330 ERROR org.apache.zookeeper.server.persistence.Util: [myid:16] - [main:Util@239] - Last transaction was partial.
2021-10-11 17:07:08,331 ERROR org.apache.zookeeper.server.quorum.QuorumPeer: [myid:16] - [main:QuorumPeer@453] - Unable to load database on disk
java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.persistence.FileHeader.deserialize(FileHeader.java:64)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.inStreamCreated(FileTxnLog.java:558)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.createInputArchive(FileTxnLog.java:577)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.goToNextLog(FileTxnLog.java:543)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.next(FileTxnLog.java:625)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.init(FileTxnLog.java:529)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.<init>(FileTxnLog.java:504)
        at org.apache.zookeeper.server.persistence.FileTxnLog.read(FileTxnLog.java:341)
        at org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:132)
        at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:223)
        at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:417)
        at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:409)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:151)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:111)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:78)
2021-10-11 17:07:08,332 ERROR org.apache.zookeeper.server.quorum.QuorumPeerMain: [myid:16] - [main:QuorumPeerMain@89] - Unexpected exception, exiting abnormally
java.lang.RuntimeException: Unable to run quorum server 
        at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:454)
        at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:409)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:151)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:111)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:78)
Caused by: java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.persistence.FileHeader.deserialize(FileHeader.java:64)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.inStreamCreated(FileTxnLog.java:558)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.createInputArchive(FileTxnLog.java:577)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.goToNextLog(FileTxnLog.java:543)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.next(FileTxnLog.java:625)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.init(FileTxnLog.java:529)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.<init>(FileTxnLog.java:504)
        at org.apache.zookeeper.server.persistence.FileTxnLog.read(FileTxnLog.java:341)
        at org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:132)
        at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:223)
        at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:417)
        ... 4 more

7 问题解决

通过以上通用问题排查思路,我们查看日志找到了问题原因:zk 底层存储在本地文件系统中的文件 /var/license/version-2/snapshot.70000007a 损坏了,所以无法启动。 由于集群中 zk 是有多个节点的,且其它节点的 zk 启动是成功的,所以我们 可以删除该问题节点上述目录下的数据文件,然后重启该节点的 zk, 重启后该节点的 zk 就可以从其它节点复制数据到本地,就可以正常对外提供服务了!
zk 底层存储在本地文件系统中的文件,在正常节点于问题节点,对比截图如下:

zk data on good node
zk data on good node
zk data on bad node
zk data on bad node

按照上述方法,清空目录重启zk后,kubectl get pods 查看服务正常,截图如下:

kubectl-get-pods-after-fix
kubectl-get-pods-after-fix

注意:其实 zk 也提供了系统工具 zkCleanup.sh 来清理本地数据文件,笔者没有使用该工具,而是手工备份和清空了问题节点的本地文件。大家可以自行尝试该工具。

zkCleanup.sh
zkCleanup.sh

8 知识总结

  • 大数据从业者,需要不断扩展自己的技能包,掌握 Kubernetes 和 Docker 的基础知识和常见命令,才能在排查大数据相关问题时不至于捉襟见肘,因技能储备短缺,无从下手;
  • 某个 pod 处于 CrashloopBackOff, 意味着该 pod 中的容器被启动了,然后崩溃了,接下来又被自动启动了,但又崩溃了,如此周而复始,陷入了(starting, crashing, starting,crashing)的循坏;
  • 当 pod 容器底层的应用程序运行出现故障时,通用的排查思路,一般是:
    1. 步骤一:通过命令 kubectl describe pod xxx 获取 pod 详细信息;
    2. 步骤二:通过命令 kubectl logs xxx 查看 pod 容器底层的应用程序的日志;
    3. 步骤三:进一步获取并查看 pod 容器底层的应用程序的其它日志文件,深挖问题原因;
  • kubectl logs 展示的是 pod 底层的 container 的标准输出 stdout 和标准错误 stderr 的日志, 应用程序写到其它文件的日志,kubectl logs 展示不了,需要获取日志文件路径,并自行查看;
  • k8s 建议应用程序将日志写到 container 的标准输出 stdout 和标准错误 stderr;
  • 容器内的应用程序可以将日志直接写到 container 的标准输出 stdout 和标准错误 stderr;如果容器内的应用程序不能或不方便将日志直接写到 container 的标准输出 stdout 和标准错误 stderr,可以使用 sidecar 即边车模式,在应用程序的 container 所在的 pod 内部署另一个 sidecar container,该 sidecar container 负责读取应用程序的日志文件并输出到其标准输出 stdout 和标准错误 stderr 里;
  • k8s 在底层会通过运行在各个节点的 kubelet 来收集节点中所有 container 的 stdout 和 stderr 日志,并写到一个 kubelet 管理的本地文件中;
  • 用户执行 kubectl logs xx 命令时,该命令在底层会调用该 container 对应节点上的 kubelet 来检索其管理的本地日志文件,以获取日志;
  • 用户使用 kubectl log xxx 来检索应用程序日志,省去了用户登录 k8s 集群中对应节点查看对应日志的繁琐操作,提供了很大遍历;
  • 排查问题,需要大胆猜想小心求证!

!关注不迷路~ 各种福利、资源定期分享!欢迎小伙伴们扫码添加明哥微信,后台加群交流学习。

IT明哥
IT明哥

IT明哥

2021/10/13  阅读:37  主题:默认主题

作者介绍

IT明哥