大家好，我是明哥！

本片文章介紹下 Kubernetes 應用問題的通用排查思路，分享一個線上此類問題的排查案例，總結下背后的相關知識，以饗讀者，大家共勉！

1 技術趨勢大背景

我們知道，大數據進一步發展的一個趨勢，就是大數據和云計算進一步融合（包括在底層更加青睞存儲計算分離的架構，在底層更加青睞對象存儲），在部署架構上支持混合云和多云場景，擁抱云計算走向云原生化。

對應到底層具體技術堆棧上，體現在各個主流大數據平臺和底層的大數據組件，紛紛開始支持以 Kubernetes 和 Docker 為代表的容器系列技術棧。

所以大數據從業者，需要不斷擴展自己的技能包，掌握 Kubernetes 和 Docker 的基礎知識和常見命令，才能在排查大數據相關問題時不至于捉襟見肘，因技能儲備短缺，無從下手。

從技術視角看大數據行業的發展趨勢

在此分享一個大數據平臺中 docker 容器相關故障的排查案列，并介紹下此類問題的背后知識和排查思路，以饗讀者，大家共勉！

2 問題現象

星環大數據平臺 TDH 中， zookeeper 服務無法正常啟動。我們知道 TDH 中，各個服務其實是在 k8s 的管控下運行于 docker 容器中，通過 kubectl get pods -owide |grep -i zoo 可以發現，對應的 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 容器底層的應用程序運行出現故障時，通用的排查思路，一般是：

• 步驟一：通過命令 kubectl describe pod xxx 獲取 pod 詳細信息
• 步驟二：通過命令 kubectl logs xxx 查看 pod 容器底層的應用程序的日志
• 步驟三：進一步獲取并查看 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

該命令的詳細輸出如下：

1. kubectldescribepodzookeeper-server-license-7fbfc544fc-h8nn9
2. Name:zookeeper-server-license-7fbfc544fc-h8nn9
3. Namespace:default
4. Priority:0
5. PriorityClassName:
6. Node:uf30-tdh3-regression/10.20.159.115
7. StartTime:Mon,11Oct202116:56:30+0800
8. Labels:name=zookeeper-server-license
9. pod-template-hash=3969710097
10. podConflictName=zookeeper-server-license
11. Annotations:
12. Status:Running
13. IP:10.20.159.115
14. ControlledBy:ReplicaSet/zookeeper-server-license-7fbfc544fc
15. Containers:
16. zookeeper-server-license:
17. ContainerID:docker://0887c97ab185f1b004759e8c85b48631f511cb43088424190c3f27c715bb8414
18. Image:transwarp/zookeeper:transwarp-6.0.2-final
19. ImageID:docker-pullable://transwarp/zookeeper@sha256:19bf952dedc70a1d82ba9dd9217a2b7e34fc018561c2741d8f6065c0d87f8a10
20. Port:
21. Args:
22. boot.sh
23. LICENSE_NODE
24. State:Terminated
25. Reason:Error
26. ExitCode:1
27. Started:Mon,11Oct202117:12:09+0800
28. Finished:Mon,11Oct202117:12:10+0800
29. LastState:Terminated
30. Reason:Error
31. ExitCode:1
32. Started:Mon,11Oct202117:07:07+0800
33. Finished:Mon,11Oct202117:07:08+0800
34. Ready:False
35. RestartCount:8
36. Environment:
37. ZOOKEEPER_CONF_DIR:/etc/license/conf
38. Mounts:
39. /etc/license/conffromconf(rw)
40. /etc/localtimefromtimezone(rw)
41. /etc/tos/conffromtos(rw)
42. /etc/transwarp/conffromtranswarphosts(rw)
43. /usr/lib/transwarp/pluginsfromplugin(rw)
44. /var/licensefromdata(rw)
45. /var/log/license/fromlog(rw)
46. /var/run/secrets/kubernetes.io/serviceaccountfromdefault-token-g42jt(ro)
47. /vdirfrommountbind(rw)
48. Conditions:
49. TypeStatus
50. InitializedTrue
51. ReadyFalse
52. PodScheduledTrue
53. Volumes:
54. data:
55. Type:HostPath(barehostdirectoryvolume)
56. Path:/var/license
57. HostPathType:
58. conf:
59. Type:HostPath(barehostdirectoryvolume)
60. Path:/etc/license/conf
61. HostPathType:
62. log:
63. Type:HostPath(barehostdirectoryvolume)
64. Path:/var/log/license/
65. HostPathType:
66. mountbind:
67. Type:HostPath(barehostdirectoryvolume)
68. Path:/transwarp/mounts/license
69. HostPathType:
70. plugin:
71. Type:HostPath(barehostdirectoryvolume)
72. Path:/usr/lib/transwarp/plugins
73. HostPathType:
74. timezone:
75. Type:HostPath(barehostdirectoryvolume)
76. Path:/etc/localtime
77. HostPathType:
78. transwarphosts:
79. Type:HostPath(barehostdirectoryvolume)
80. Path:/etc/transwarp/conf
81. HostPathType:
82. tos:
83. Type:HostPath(barehostdirectoryvolume)
84. Path:/etc/tos/conf
85. HostPathType:
86. default-token-g42jt:
87. Type:Secret(avolumepopulatedbyaSecret)
88. SecretName:default-token-g42jt
89. Optional:false
90. QoSClass:BestEffort
91. Node-Selectors:zookeeper-server-license=true
92. Tolerations:node.kubernetes.io/not-ready:NoExecutefor300s
93. node.kubernetes.io/unreachable:NoExecutefor300s
94. Events:
95. TypeReasonAgeFromMessage
96. -------------------------
97. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"default-token-g42jt"
98. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"conf"
99. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"tos"
100. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"mountbind"
101. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"transwarphosts"
102. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"log"
103. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"plugin"
104. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"data"
105. NormalSuccessfulMountVolume15mkubelet,uf30-tdh3-regressionMountVolume.SetUpsucceededforvolume"timezone"
106. NormalScheduled15mdefault-schedulerSuccessfullyassignedzookeeper-server-license-7fbfc544fc-h8nn9touf30-tdh3-regression
107. NormalPulled15m(x3over15m)kubelet,uf30-tdh3-regressionSuccessfullypulledimage"transwarp/zookeeper:transwarp-6.0.2-final"
108. NormalCreated15m(x3over15m)kubelet,uf30-tdh3-regressionCreatedcontainer
109. NormalStarted15m(x3over15m)kubelet,uf30-tdh3-regressionStartedcontainer
110. NormalPulling15m(x4over15m)kubelet,uf30-tdh3-regressionpullingimage"transwarp/zookeeper:transwarp-6.0.2-final"
111. WarningBackOff44s(x70over15m)kubelet,uf30-tdh3-regressionBack-offrestartingfailedcontainer

6.2 問題排查復盤：通過命令 kubectl logs xxx 查看 pod 容器底層的應用程序的日志

接下來我們嘗試通過命令 kubectl logs xxx 查看 pod 容器底層的應用程序的日志，以期找到問題的原因，該命令的輸出部分截圖如下所示：圖片

如上圖所見，不幸的是，該命令的輸出，沒有展示出問題的根本原因。

在底層日志機制上，應該是星環 tdh 中該 zk 應用沒有將日志打印到標準輸出 stdout 和標準錯誤 stderr, 所以 kubectl logs xxx 查看不到對應的日志。

我們需要進一步排查。

6.3 問題排查復盤：進一步獲取并查看 pod 容器底層的應用程序的其它日志文件，深挖問題原因

進一步排查問題，我們首先需要獲取 pod 容器底層的應用程序的其它日志文件的路徑。

由于 tdh 是閉源的，我們查看不到應用程序的源碼，在沒有聯絡官方客戶的情況下，我們可以通過命令 kubectl describe pod xxx 查看該 pod 掛載了哪些 volume，然后猜測并驗證獲得具體的日志文件的路勁給，（排查問題就是要，大膽猜想，小心求證！）

該命令輸出的部分截圖如下，我們看到其中掛載了路徑 /var/log/license:

接下來我們查看這些日志文件/var/log/license，嘗試深挖問題原因，注意，該文件是本地文件系統的文件，需要登錄到對應的節點上去查看，該日志文件部分關鍵截圖如下：

通過日志，問題原因找到了：zk 底層存儲在本地文件系統中的文件 /var/license/version-2/snapshot.70000007a 損壞了，所以無法啟動:

1. 2021-10-1117:07:08,330ERRORorg.apache.zookeeper.server.persistence.Util:[myid:16]-[main:Util@239]-Lasttransactionwaspartial.
2. 2021-10-1117:07:08,331ERRORorg.apache.zookeeper.server.quorum.QuorumPeer:[myid:16]-[main:QuorumPeer@453]-Unabletoloaddatabaseondisk
3. java.io.EOFExceptionatjava.io.DataInputStream.readInt(DataInputStream.java:392)

該日志文件詳細內容如下：

1. tail-50/var/log/license/zookeeper.log
2. 2021-10-1117:07:08,203INFOorg.apache.zookeeper.server.DatadirCleanupManager:[myid:16]-[main:DatadirCleanupManager@101]-Purgetaskisnotscheduled.
3. 2021-10-1117:07:08,212INFOorg.apache.zookeeper.server.quorum.QuorumPeerMain:[myid:16]-[main:QuorumPeerMain@127]-Startingquorumpeer
4. 2021-10-1117:07:08,221INFOorg.apache.zookeeper.server.NIOServerCnxnFactory:[myid:16]-[main:NIOServerCnxnFactory@94]-bindingtoport0.0.0.0/0.0.0.0:2291
5. 2021-10-1117:07:08,235INFOorg.apache.zookeeper.server.quorum.QuorumPeer:[myid:16]-[main:QuorumPeer@913]-tickTimesetto9000
6. 2021-10-1117:07:08,235INFOorg.apache.zookeeper.server.quorum.QuorumPeer:[myid:16]-[main:QuorumPeer@933]-minSessionTimeoutsetto-1
7. 2021-10-1117:07:08,235INFOorg.apache.zookeeper.server.quorum.QuorumPeer:[myid:16]-[main:QuorumPeer@944]-maxSessionTimeoutsetto-1
8. 2021-10-1117:07:08,236INFOorg.apache.zookeeper.server.quorum.QuorumPeer:[myid:16]-[main:QuorumPeer@959]-initLimitsetto10
9. 2021-10-1117:07:08,285INFOorg.apache.zookeeper.server.persistence.FileSnap:[myid:16]-[main:FileSnap@83]-Readingsnapshot/var/license/version-2/snapshot.70000007a
10. 2021-10-1117:07:08,330ERRORorg.apache.zookeeper.server.persistence.Util:[myid:16]-[main:Util@239]-Lasttransactionwaspartial.
11. 2021-10-1117:07:08,331ERRORorg.apache.zookeeper.server.quorum.QuorumPeer:[myid:16]-[main:QuorumPeer@453]-Unabletoloaddatabaseondisk
12. java.io.EOFException
13. atjava.io.DataInputStream.readInt(DataInputStream.java:392)
14. atorg.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
15. atorg.apache.zookeeper.server.persistence.FileHeader.deserialize(FileHeader.java:64)
16. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.inStreamCreated(FileTxnLog.java:558)
17. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.createInputArchive(FileTxnLog.java:577)
18. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.goToNextLog(FileTxnLog.java:543)
19. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.next(FileTxnLog.java:625)
20. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.init(FileTxnLog.java:529)
21. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.(FileTxnLog.java:504)
22. atorg.apache.zookeeper.server.persistence.FileTxnLog.read(FileTxnLog.java:341)
23. atorg.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:132)
24. atorg.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:223)
25. atorg.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:417)
26. atorg.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:409)
27. atorg.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:151)
28. atorg.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:111)
29. atorg.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:78)
30. 2021-10-1117:07:08,332ERRORorg.apache.zookeeper.server.quorum.QuorumPeerMain:[myid:16]-[main:QuorumPeerMain@89]-Unexpectedexception,exitingabnormally
31. java.lang.RuntimeException:Unabletorunquorumserver
32. atorg.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:454)
33. atorg.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:409)
34. atorg.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:151)
35. atorg.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:111)
36. atorg.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:78)
37. Causedby:java.io.EOFException
38. atjava.io.DataInputStream.readInt(DataInputStream.java:392)
39. atorg.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
40. atorg.apache.zookeeper.server.persistence.FileHeader.deserialize(FileHeader.java:64)
41. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.inStreamCreated(FileTxnLog.java:558)
42. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.createInputArchive(FileTxnLog.java:577)
43. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.goToNextLog(FileTxnLog.java:543)
44. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.next(FileTxnLog.java:625)
45. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.init(FileTxnLog.java:529)
46. atorg.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.(FileTxnLog.java:504)
47. atorg.apache.zookeeper.server.persistence.FileTxnLog.read(FileTxnLog.java:341)
48. atorg.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:132)
49. atorg.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:223)
50. atorg.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:417)
51. ...4more

7 問題解決

通過以上通用問題排查思路，我們查看日志找到了問題原因：zk 底層存儲在本地文件系統中的文件 /var/license/version-2/snapshot.70000007a 損壞了，所以無法啟動。由于集群中 zk 是有多個節點的，且其它節點的 zk 啟動是成功的，所以我們 可以刪除該問題節點上述目錄下的數據文件，然后重啟該節點的 zk， 重啟后該節點的 zk 就可以從其它節點復制數據到本地，就可以正常對外提供服務了！

zk 底層存儲在本地文件系統中的文件，在正常節點于問題節點，對比截圖如下：

zk data on good node

zk data on bad node

按照上述方法，清空目錄重啟zk后，kubectl get pods 查看服務正常，截圖如下：

kubectl-get-pods-after-fix

注意：其實 zk 也提供了系統工具 zkCleanup.sh 來清理本地數據文件，筆者沒有使用該工具，而是手工備份和清空了問題節點的本地文件。大家可以自行嘗試該工具。

zkCleanup.sh

8 知識總結

• 大數據從業者，需要不斷擴展自己的技能包，掌握 Kubernetes 和 Docker 的基礎知識和常見命令，才能在排查大數據相關問題時不至于捉襟見肘，因技能儲備短缺，無從下手;
• 某個 pod 處于 CrashloopBackOff， 意味著該 pod 中的容器被啟動了，然后崩潰了，接下來又被自動啟動了，但又崩潰了，如此周而復始，陷入了（starting, crashing, starting，crashing）的循壞;
• 當 pod 容器底層的應用程序運行出現故障時，通用的排查思路，一般是：

步驟一：通過命令 kubectl describe pod xxx 獲取 pod 詳細信息;

步驟二：通過命令 kubectl logs xxx 查看 pod 容器底層的應用程序的日志;

步驟三：進一步獲取并查看 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 集群中對應節點查看對應日志的繁瑣操作，提供了很大便利；
• 排查問題，需要大膽猜想小心求證！

原文鏈接：https://mp.weixin.qq.com/s/qA3dHhsOQtu56UNwn-tsLQ