天天看點

記一次docker問題定位

記一次docker問題定位

原創   2018-04-25   孫庚澤   性能測試發現業務程序運作在容器中比業務程序運作在主控端上吞吐量下降了 100 倍,這讓周一顯得更加陰暗。     背景   

最近參與的項目是基于 OpenStack 提供容器管理能力,豐富公司 IaaS 平台的能力。日常主要工作就是在開源的 novadocker 項目(開源社群已停止開發)基礎上進行增強,與公司的其他業務元件進行對接等。

周末給下遊部門的 IaaS 平台進行了一次更新,主要更新了底層作業系統,基本用例跑通過,沒出現什麼問題,皆大歡喜。

結果周一一到公司就傳來噩耗,性能測試發現業務程序運作在容器中比業務程序運作在主控端上吞吐量下降了 100 倍,這讓周一顯得更加陰暗。

   周一   

先找下遊了解了下業務模型,他們說已經把業務模型最簡化了,目前的模式是:業務程序運作在容器中,通過與主機共享 IPC namespace 的方式來使用共享記憶體與主控端上的 Daemon 程序進行通信,整個過程不涉及磁盤讀寫、網絡互動等。

撸起袖子開始幹,定位第一步,當然是找瓶頸了,分析下到底問題出在哪。

   top   

用到的第一個指令自然是 top,top 是 linux 裡一個非常強大的指令,通過它基本上能看到系統中的所有名額。

記一次docker問題定位

上面是 top 指令運作時的一個示意圖,比較重要的名額都已經标了出來:

1 處表示系統負載,它表示目前正在等待被 cpu 排程的程序數量,這個值小于系統 vcpu 數(超線程數)的時候是比較正常的,一旦大于 vcpu 數,則說明并發運作的程序太多了,有程序遲遲得不到 cpu 時間。這種情況給使用者的直覺感受就是敲任何指令都卡。

2 處表示目前系統的總程序數,通常該值過大的時候就會導緻 load average 過大。

3 處表示 cpu 的空閑時間,可以反應 cpu 的繁忙程度,該值較高時表示系統 cpu 處于比較清閑的狀态,如果該值較低,則說明系統的 cpu 比較繁忙。需要注意的是,有些時候該值比較高,表示 cpu 比較清閑,但是 load average 依然比較高,這種情況很可能就是因為程序數太多,程序切換占用了大量的 cpu 時間,進而擠占了業務運作需要使用的 cpu 時間。

4 處表示程序 IO 等待的時間,該值較高時表示系統的瓶頸可能出現在磁盤和網絡。

5 處表示系統的剩餘記憶體,反應了系統的記憶體使用情況。

6 處表示單個程序的 cpu 和記憶體使用情況。關于 top 指令中各個名額含義的進一步描述可以參見:

http://www.jb51.net/LINUXjishu/34604.html

使用 top 指令檢視了下系統情況,發現一切正常。load average 也不高,task 也不多,cpu 和記憶體都還很空閑,就連 IO 等待時間都很低,也沒有哪個程序的 cpu 和記憶體使用率偏高,一切都很和諧,沒有瓶頸!

當然,沒有瓶頸是不可能的。由于我們的容器都是綁核的,是以很有可能是配置設定給容器的那些核是處于繁忙狀态,而由于總核數較多,将 cpu 的使用率給拉了下來。于是又按下了“1”鍵,切換到詳細模式下:

記一次docker問題定位

在這種模式下,可以看到每個 vcpu 的使用情況。一切依然很和諧,詭異的和諧。

看來從 cpu 這塊是看不出來什麼了,那就繼續看看是不是磁盤搞的鬼吧。

 iostate 

iostate 指令是用來檢視磁盤使用情況的一個指令,經驗告訴我們,磁盤和網絡已經成為影響性能的最大嫌疑犯。

記一次docker問題定位

使用 iostate 工具時,通常隻用關注最後一行(%util)即可,它反映了磁盤的繁忙程度。雖然下遊部門已經說了他們跑的用例是一個純記憶體的場景,不涉及磁盤讀寫。但是客戶的話信得住,母豬也能上樹,我還是要跑一下 iostate,看下磁盤情況怎麼樣。結果,依舊很和諧,磁盤使用率基本為零。

後面還嘗試了觀察網絡名額,發現确實也沒有網絡吞吐,完了,看來問題沒那麼簡單。

   周二   

雖然周一看似白忙活了一天,但是也得到了一個重要結論:這個問題不簡單!不過簡單的在資源層面時分析不出來啥了,得寄出性能分析的大殺器——perf 了。

perf+ 火焰圖

perf 是 linux 下一個非常強大的性能分析工具,通過它可以分析出程序運作過程中的主要時間都花在了哪些地方。

之前沒太使用過 perf,是以剛開始進行分析,就自然而然地直接使用上了 perf+ 火焰圖這種最常見的組合:

  1. 安裝 perf。

    yum install perf

  2. 下載下傳火焰圖工具。

    git clone https://github.com/brendangregg/FlameGraph.git

  3. 采樣。

    perf record -e cpu-clock -g -p 1572(業務程序 id)

    一段時間(通常 20s 足夠)之後 ctrl+c,結束采樣。

  4. 用 perf script 工具對 perf.data 進行解析。

    perf script -i perf.data &> perf.unfold。

    PS:如果在容器中運作的程式有較多的依賴,則該指令解析出來的符号中可能會有較多的“Unregistered symbol…”錯誤,此時需要通過

    --symfs

    參數指定容器的

    rootfs

    位置來解決該問題。擷取容器

    rootfs

    的方法根據 docker 的 storagedriver 的不同而有所不同,如果是

    device mapper

    類型,則可以通過 dockerinspect 找到容器的

    rootfs

    所在位置,如果是

    overlay

    類型,則需要通過 dockerexport 指令将該容器的

    rootfs

    導出來,如果是富容器的話,一般都有外置的

    rootfs

    ,直接使用即可。
  5. 将 perf.unfold 中的符号進行折疊。

    ./stackcollapse-perf.pl perf.unfold &> perf.folded

  6. 最後生成 svg 圖。

    /flamegraph.pl perf.folded > perf.svg

最後就能得到像下面這種樣子的漂亮圖檔。通常情況下,如果程式中有一些函數占用了大量的 CPU 時間,則會在圖檔中以長橫條的樣式出現,表示該函數占用了大量的 CPU 時間。

然而,perf+ 火焰圖在這次并沒有起到太大的作用,反複統計了很多次,并沒有出現夢寐以求的“長橫條”,還是很和諧。

perf stat

perf+ 火焰圖并沒有起到很好的效果,就想換個工具繼續試試,但是找來找去、請教大神,也沒找到更好的工具,隻好繼續研究 perf 這個工具。

perf 除了上面提到的 record(記錄事件)、script(解析記錄的事件)指令之外,還有其他一些指令,常用的有 report(與 script 類似,都是對 perf record 記錄的事件進行解析,不同之處在于 report 直接解析程式中的運作熱點,script 的擴充性更強一點,可以調用外部腳本對事件資料進行解析)、stat(記錄程序一段時間之内觸發的事件數)、top(實時分析程式運作時熱點)、list(列出 perf 可以記錄的事件數)等指令。

這些指令挨個試了個遍,終于在 perf stat 指令這塊有了突破:

使用 perf stat 對業務程序運作在實體機和容器上分别進行統計,發現業務程序運作在容器中時,大部分事件(task-clock、context-switches、cycles、instructions 等)的觸發次數是運作在實體機上時的百分之一。

這是什麼原因呢?一定是什麼東西阻塞住了程式的運轉,這個東西是什麼呢?

前面已經分析了,不是磁盤,不是網絡,也不是記憶體,更不是 cpu,那還有什麼呢??

   周三   

是什麼原因阻塞住了程式的運轉呢?百思不得其解,百問不得其解,百猜不得其解,得,還是得動手,上控制變量法。

運作在容器中的程式和運作在實體機上有什麼差別呢?我們知道,docker 容器 =cgroup+namespace+secomp+capability+selinux,那麼就把這些技術一個個都去掉,看到底是哪個特性搞的鬼。

在這 5 個技術中,後三個都是安全相關的,都有開關可以控制,經過測試,發現把後三個都關掉之後,性能還是很差,說明這 3 個技術是無辜的,開始排查 cgroup 和 namespace。

首先懷疑的當然是 cgroup,畢竟它就是做資源限制的,很有可能一不小心限制錯了,就把業務給限制了。

cgexec

cgexec 是 cgroup 提供的一個工具,可以在啟動時就将程式運作到某個 cgroup 中,是以我們可以将業務程式運作在實體機上,但是放到業務容器所在的 cgroup 中,看看性能會不會下降。

具體用法如下:

cgexec -g *:/system.slice/docker-03c2dd57ba123879abab6f7b6da5192a127840534990c515be325450b7193c11.scope ./run.sh
           

通過該指令即可将 run.sh 運作在與容器 03c2dd57 相同的 cgroup 中。在多次測試之後,發現這種情況下,業務程序的運作速度沒有受到影響,cgroup 被洗白,那麼真相隻有一個——兇手就是 namespace。

   周四   

雖然說兇手已經确定是 namespace,但是 namespace 家族也有一大票人,有 ipc namespace、pid namespace 等等,還需要進一步确定真兇。

nsenter

nsenter 是一個 namespace 相關的工具,通過它可以進入某個程序所在的 namespace。在 docker exec 指令出現之前,它唯一一個可以進入 docker 容器的工具,在 docker exec 出現之後,nsenter 也由于其可以選擇進入哪些 namespace 而成為 docker 問題定位的一個極其重要的工具。

通過如下指令,即可進入容器所在的 mount namespace。

nsenter --target $(docker inspect --format '{{.State.Pid}}' 容器 id) --mount bash
           

同理,通過如下指令即可進入容器所在的 IPC namespace 和 pid namespace。

nsenter --target $(docker inspect --format '{{.State.Pid}}' 容器 id) --ipc --pid bash
           

在不斷的将業務程序在各個 namespace 之間切換後,終于進一步鎖定了真兇:mount namespace。測試發現,一旦将業務程序放置到容器所在的 mount namespace,性能就會急劇下降。

這是為什麼呢?這是為什麼呢?mount namespace 到底做了什麼,會有這麼大的影響?

離開公司時已經時 12 點,隔壁工位的專家還在那電話會議,“我看哈,這一幀,在這個節點還是有的,但是到了這呢,就沒了,它。。”,“那是找到丢包原因了?”,“别急嘛,我慢慢看,看這個節點。”。

在回家的計程車上,想想這個問題已經四天了,想想隔壁工位的專家都要成神了,還是會遇到棘手的問題,突然有種崩潰的感覺,費了九牛二虎之力猜把眼淚憋回去,不然還真怕吓着計程車師傅。

   周五   

早上起床還和女朋友談起這事,說我最近遇到了一個大難題,想想已經好多年沒遇到這麼難搞的問題了。上一次遇到這種級别的問題,還是大四剛進實驗室的時候,那時候有個問題花了一整周的時間才解決。要是今天我還解決不了這個問題,就破記錄了。

記得當時是需要在實驗室搭建 eucalyptus 叢集,之前每次搭建都很順利,但是那次卻奇怪,怎麼都搭建不成功,研究了一周之後,才發現是因為那台伺服器的 bios 時間被還原了,eucalyptus 在安裝過程中發現目前時間不在自己的有效時間内(太早了),是以一直安裝失敗。

言歸正傳,mount namespace 為什麼有這麼大的威力呢?它到底影響什麼了呢?實在想不通,就去請教了下大神,大神想了想,回了我句,試試 ldd?

ldd

ldd 是什麼?

當然這句話我沒去問大神,轉身自己查去了。

ldd 是 list, dynamic, dependencies 的縮寫,意思是列出動态庫依賴關系。頓時豁然開朗,mount namespace 隔離出了自己的檔案系統,是以容器内外可以使用不同的依賴庫,而不同的依賴庫就可能造成無數種影響。

于是開始通過 ldd 對比容器中業務程序的依賴庫與主控端上業務程序的依賴庫,最終發現容器中的 glibc 庫與主控端上的 glibc 庫版本不一緻,很可能是這個原因導緻性能下降的。

于是将容器中的 glibc 庫版本替換為主控端上的 glibc 庫之後,容器内業務的性能終于恢複了,猜想得到證明。

下班回家,一身輕松!

路過隔壁工位的專家時候,他剛好起身接水,順口問道,“怎麼樣,平哥,丢失的那一幀找到沒?”,“嗨,别提了,繼續看”

   後記   

為什麼容器内外 glibc 版本不一緻就導緻性能下降了呢?

這是和業務模型相關的,前面提到,下遊的業務模型是通過與主機共享 IPC namespace 的方式來使用共享記憶體與主控端上的 daemon 程序進行通信。而 glibc 在一次更新中,更新了信号量的資料結構(如下),就會導緻在共享記憶體通信時,由于資料格式不一緻,每次信号量通信都逾時,進而影響了程式運作效率。