804      阿裏雲  技術社區[雲棲]

統計工具R在排查和診斷中的實戰

排查和診斷需要統計工具？

排查和診斷過程，就是數據處理過程。

有時候隻要處理過程探索到一個信號出現了就足以確定致因和解決問題了，至少也會得到進一步的線索。比如，客戶ECS並發訪問量上不去，如果發現對進程能打開多少文件描述符有限製。那麼，我們差不多就確定了致因，對於如何解決問題也有了答案。

我們可以把上麵排查和診斷的過程規範化為基於數據回答問題的過程。對這個過程，我們的預期是找到一個信號，這個信號可以確定致因，同時也對解決問題給出線索或者依據。比如，上麵的例子，我們就是基於ECS的係統日誌、業務日誌和運行時信息來回答“為什麼並發量上不去”問題的過程。過程的結果是我們找到了進程能打開文件描述符數量受限這個信號。

如果就問題和致因信號關係而言，上麵提到的例子是簡單的。因為問題和信號出現與否有關，是非此即彼的關係。簡單計，我們把這種關係稱之為“二進製關係”。也就是說，信號出現，就會導致問題。這種情況下，簡單的cat、grep命令探索數據，搜尋確認信號出現與否就足夠了。但是，如果問題和信號之間的關係不是這種非此即彼的二進製關係，比如，是和信號出現的頻率有關係。這種情況下，如果信號往往是在數天甚至幾周內都有出現，即使我們基於經驗能夠把信號和問題聯係起來，可能也不易讓客戶接受我們的排查和診斷過程以及結論，而且僅憑經驗，也有不小的誤判概率。

更為複雜的情形可能是問題和數據中某些信號集合的某些整體的特征相關。這些特征不使用工具統計匯總就無法被識別和確認。比如，與某個信號在一分鍾內連續出現的頻率有關，而與一分鍾內出現的、總的次數關係不大。這種情形下，直接的觀察是很難處理的，尤其是數據量比較大時。因此，我們需要工具改善排查和診斷過程。

對於因果之間沒有簡單對應關係的情形，抽象模型和處理方式，無論是理論還是實踐，都是種類繁多。這裏我們隻介紹和引入傳統的統計手段。

什麼是R以及為什麼選擇R？

大多數編程語言，在其是否圖靈完備的意義上，是沒有區別的。但是，不同語言提供的抽象支持，在生產力和軟件工程方麵卻相差懸殊。比如，把一個文件的內容輸出到終端上，使用cat命令，估計簡單了解過UNIX環境的工程師都可以；但是用匯編語言來做，估計得難道一大片。

那麼，什麼是R呢？學究一點，R是以統計處理為其領域的編程語言和平台。通俗一點，R是一個統計工具。就是說，R是圍繞著統計來提供其抽象的，正如C++、Java、和Ruby是圍繞對象來提供抽象的。

但是，對於諸多統計軟件平台，就易用性和學習曲線而言，諸如SPSS和SAS等商用軟件無疑是占有優勢的。而開源軟件，也不止R一家。比如Python社區就提供了多種實現供選擇。而且現在還有Figaro，自稱

Figaro is a probabilistic programming language that supports development of very rich probabilistic models and provides reasoning algorithms that can be applied to models to draw useful conclusions from evidence. Both model representation and reasoning algorithm development can be challenging tasks.

那麼，我們為什麼選擇R這個平台呢？

首先，R是S語言的一個開源實現，S出身AT&T。因此R可以和UNIX經典工具等適配使用。

除此之外，在某種意義上，你可以把R看成是實現了M-expression的Scheme的一種實現。你在函數式編程裏看到的各種玄妙都可以在R中嚐試一番。

再者，R提供了強大的繪圖能力。一圖勝千言，尤其是在和客戶交流時。

最後一點，有眾多的以R為主題的出版書籍；google內部大規模使用了R；微軟在其產品裏直接支持R。

因此，R是個不錯的選擇。其作為語言既有命令式語言的語法，又有函數式編程的核，又因其目標領域是統計，因此又能改變你的思考方式 ，加之重量客戶的投入，可以預期你的投資很有保證。如果正在提升自己，或者計劃提升自己，為什麼不選擇R呢？

如何安裝、啟動和退出R以及安裝R包？

R作為開源軟件，支持Windows、MacOS和Linux等主流平台，但是官方安裝手冊隻提供了編譯安裝方式。其實，對於Linux和MacOS，都有軟件包管理軟件可用，直接通過這樣的工具安裝即可。

安裝

比如，對於MacOS，隻要部署了homebrew可用，可以這樣安裝

brew cask install r-app 

對於Linux係統，如果是RHEL-like係統，比如，Fedora或者CentOS（在較新的Fedora中請使用dnf替換yum；CentOS中需要部署EPEL的源），可以這樣安裝

yum -y install R

對於Debian/Ubuntu，可以這樣安裝

apt-get -y install r-base

對於Windows（其實也包括MacOS和Linux），其官方網站提供了預編譯的二進製包，直接下載安裝即可。當然，微軟自己也提供了增強版本，感興趣請到MRAN下載。

除了R，這裏也推薦RStudio，R的IDE， 直接下載安裝就好。

啟動和退出R

鑒於被困在不熟悉的軟件中無法退出都成了頭條，為了避免惡劣的第一印象，我們對於如何退出R，特意說明下。

其實，如果使用的是圖形界麵，那麼你如何操作瀏覽器窗口，就怎麼操作R的圖形界麵就好。如果是使用的是終端界麵呢？

進入R

R

退出R

q()

使用上麵的退出方式，R會要求確認是否保存工作區。如果你想不確認就退出，那麼你不想保存，那麼

q(save="no") 

如果想要保存，那麼

q(save="yes")

安裝R包

由Perl其，流行的腳本語言都有一個類似CPAN的站點，R也不例外。因此，我們可以按需從CRAN下載、安裝需要的包。

在使用圖形界麵時，可以選擇恰當的菜單，填入相應的包名稱即可。細節請參考圖形界麵的幫助頁。對於終端用戶，可這樣處理

install.packages(c("ggplot2", "lubridate"))

R在排查和診斷過程中的位置

R在排查和診斷過程中的位置，可以用韋恩圖表示如下。額外說明下這裏的“黑客技術”不是指腳本小子或者駭客技術。

熱身準備

安裝必需的R包

接下來我們用兩個實際排查的case來介紹R。在開始之前，因為後續需要，我們要先安裝兩個R包。啟動R後，請在R中執行如下命令

install.packages(c("ggplot2", "lubridate"))

這兩個包，ggplot2用以繪圖，lubridate用以處理日期時間。

沒有為處理時間日期熬過夜的人不足以論技術。

內容說明

我們用兩個實際case來說明R在排查和診斷中的用途以及如何使用之。如何處理的第一個case，我們給出詳細步驟。第二個case，從簡。

處理流程

通用的數據處理

數據處理，我們以OSEMN為框架

1. obtaining data/獲取數據
2. crubbing data/清洗數據
3. exploring data/探索數據
4. modeling data/建模數據
5. interpreting data/解釋數據

具體處理流程

我們把上述通用的處理流程改造如下，後續我們就使用之

第一個case：症狀和初步排查

補充說明

因客戶誤操作，排查用的實例被突然釋放了。因此，整個排查過程實際上前後是在兩台不同的實例上進行的。這是為什麼在此case中，後續部分步驟和數據有時會提到到兩台實例。

症狀

客戶:

大批量ECS服務器遇到...CPU被打滿的問題，主要消耗在cpu_sys上。

相應的CPU監控數據如下

初步分析

開始我們先排查是不是資源爭搶問題。但根據雲台的監控數據，我們很快排除了這種可能。物理機有48顆CPU，但是僅有一個CPU波動較大，而且其他47顆CPU的消耗都不高。盡管物理機的CPU的消耗與實例CPU消耗有同步現象，空閑率也同步有所下降，但波動非常輕微，物理機上的總的CPU消耗和負載變動不大。並且總的CPU資源非常寬鬆。單獨CPU的監控數據也佐證了這一點。因此可以斷定是客戶的業務邏輯導致的其實例CPU消耗較高。因此排查繼續。

物理機監控數據如下

第一個case：分析係統日誌

因為CPU消耗升高的時間點已知，檢查對應時點前後的messages日誌，立刻有發現。rsyslog的omkafka插件報告報警信息

Failed to produce to topic 'mkApiNginx' partition 1: Local: Queue full

因此立刻校驗*rsyslog*軟件包，看看有哪些東西被變更。結果很快發現/etc/rsyslog.conf配置文件有變更

因此，客戶的實例應該有一個把G級別日誌傳遞出去的操作。IO/Network的監控數據佐證了這一點

但是，根據時間戳，這個原因隻能解釋實例CPU很短時間內的一個波動。因此，排查繼續。

第一個case：分析業務日誌

客戶實例上的係統日誌沒有更多的內容供分析了。所以，接下來我們轉向客戶的業務日誌。因為我們知道CPU消耗高的時間段，因此，需要找出所有的日誌逐一核實具體時間段的記錄

find / ! \( -path "/dev/*" -o -path "/proc/*" -o -path "/sys/*" -o -path "/var/*" \) -name "*log" | less

這裏我們給出第二台實例上CPU占用100%的監控數據

對於找到的文件，我們逐一手工檢查其內容，重點是CPU消耗升高的時間點前後。 很快，一個日誌裏反複出現的超時循環操作引起了我們的注意

但問題是，這個循環從06:40到23:30之間頻繁出現，但並不是整個時間段內CPU消耗都高。因此，如何確認超時循環操作和CPU消耗高之間的關係呢？僅憑觀察肯定不行了。所以，我們引入R。

數據獲取和數據清洗

我們先把日誌下載到本地， 而後我們先清洗數據。

首先過濾出所有的超時循環

grep 'Yar_Concurrent_Client::loop():' warning.log > clean_data

接著，用filter.pl腳本把一分鍾內每次連續執行的次數統計出來

#!/usr/bin/perl

use strict;
use warnings;
use feature qw(say);

my $curr = q[];
my $prev = q[];
my $count = 0;
while (<>) {
    chomp;
    next if (!m!Yar_Concurrent_Client::loop! || m!^$!);
    m!\[2017-05-20 (\d\d:\d\d):\d\d\]!;
    $curr = $1;
    if ($prev eq q[]) {
        $prev = $curr;
        $count = 1;
    }
    if ($curr eq $prev) {
        $count++;
    } else {
        say qq[$prev $count];
        $prev = $curr;
        $count = 1;
        next;
    }
}
# to print the last record
say qq[$curr $count];

腳本執行效果如下

但是，對於00:19這樣的時間表示，R中處理起來不方便。我們進一步把時間轉換成數字

perl ./filter.pl clean_data | perl -nE 'chomp;m!^(\d+):(\d+)\s+(\d+)!;my $date=$1*60+$2;say "$date $3"'

腳本執行效果如下

我們把獲取的數據放到一個文件裏，並且給數據列加上名稱以便在R裏操作

echo 'Date Freq' > data
perl ./filter.pl clean_data | perl -nE 'chomp;m!^(\d+):(\d+)\s+(\d+)!;my $date=$1*60+$2;say "$date $3"' >> data

這樣我們就拿到了數據，可以繼續操作了

數據探索

盡管為處理方便計，我們已經把時間轉為數字，但是顯示結果時最好還是看到HH:MM形式的時間，更為方便。因此，我們給R提供一個格式化
函數

timeHM_formatter <- function(x) {
  h <- floor(x/60) %% 24
  m <- floor(x %% 60)
  lab <- sprintf("%02d:%02d", h, m)
  return(lab)
}

另外，為方便R操作，我們還做一下當前目錄和本地化設置。為美觀計，我們直接使用ggplot2包。

setwd("./R/case1")
Sys.setlocale(locale="zh_CN.UTF-8")
library(ggplot2)

首先，加載數據

CPU_OCUPATION = read.table(, header=TRUE)

我們先粗略地看看數據分布的情況

summary(CPU_OCUPATION$Freq)

收獲不多

再通過散點圖看看

qplot(CPU_OCUPATION$Date, CPU_OCUPATION$Freq) + 
geom_point(colour="red") +
scale_x_continuous(name="date", breaks=seq(0, 1500, by=80), labels=timeHM_formatter) + 
scale_y_continuous(name="loop density", breaks=seq(0, 120, by=5))

仔細和CPU消耗的監控數據比較，會發現CPU消耗高在時間段，也是散點圖的熱點區域

有了這個發現，根據時間段，我們能夠確認CPU消耗高和散點圖的熱點是一一對應的

如果我們把散點圖做適當的平移和反轉操作，則對應就更明顯

那麼，我們的散點圖及其熱點區域表達的是什麼意義呢？

數據建模

我們給出的散點圖，粗略的說，x軸顯示的是時間，y軸顯示的是超時循環執行的次數。根據探索得出的結論，CPU飆高與超時循環有關，但是卻與每分鍾執行此循環總的次數關係不大。這方麵探索的細節請參考“第一個case：探索數據細節”這一章。那麼，我們在上麵小結裏給出的散點圖裏的點究竟表達了什麼呢？

為了便於理解，我們分析清洗的中間結果

perl filter.pl clean_data > middle_data

有趣的發現如下

進一步比較監控數據和我們處理的數據

即在某一時刻，連續執行超時循環的次數越多，每次連續執行時執行的超時循環的數量分布的越連續、密集，則散點圖上對應這個時刻的點就會連成一條線。如果這個時刻附近的時刻都有類似特性，就會生成色塊，形成熱點區域，此時CPU消耗會同步升高。

數據解釋

因為客戶看到散點圖後即接受了我們的排查結論，並且立刻去調整其業務邏輯了，並沒有進一步向我們解釋業務方麵的致因。因此，我們沒有辦法給出一個結合客戶業務邏輯的解釋。

第一個case：探索數據細節

探索每秒數據

一秒內可能不止一筆數據，因此我們過濾數據繼之以排序

grep 'Yar_Concurrent_Client::loop():' warning.log | sort -n > clean_data_per_min

而後由如下的filter-per-min.pl腳本做第一次處理，抽取每秒的數據。坦白說，腳本名稱應該為filter-per-sec.pl

#!/usr/bin/perl

use strict;
use warnings;
use feature qw(say);

my $curr = q[];
my $prev = q[];
my $count = 0;
while (<>) {
    chomp;
    next if (!m!Yar_Concurrent_Client::loop! || m!^$!);
    m!\[2017-05-20 (\d\d:\d\d:\d\d)\]!;
    $curr = $1;
    if ($prev eq q[]) {
        $prev = $curr;
        $count = 1;
    }
    if ($curr eq $prev) {
        $count++;
    } else {
        say qq[$prev $count];
        $prev = $curr;
        $count = 1;
        next;
    }
}
# to print the last record
say qq[$curr $count];

腳本執行效果如下

同樣，把時間日期轉換為數字

perl ./filter-per-min.pl clean_data_per_min | perl -nE 'chomp;m!^(\d+):(\d+):(\d+)\s+(\d+)!;my $date=($1*60+$2)*60+$3;say "$date $4"'

腳本執行效果如下

步驟繼續，我們把獲取的數據放到一個文件裏，並且給數據加上列名稱

echo 'Date Freq' > data_per_min
perl ./filter-per-min.pl clean_data_per_min | perl -nE 'chomp;m!^(\d+):(\d+):(\d+)\s+(\d+)!;my $date=($1*60+$2)*60+$3;say "$date $4"' >> data_per_min

這樣我們就拿到了數據，可以探究一下每秒數據了

同樣，我們提供如下格式化函數以便把時間顯示為HH:MM:SS

timeHMS_formatter <- function(x) {
  h <- floor(x/3600)
  m <- floor((x/60) %% 60)
  s <- floor(x %% 60)
  lab <- sprintf("%02d:%02d:%02d", h, m, s)
  return(lab)
}

我們加載數據，先看看數據分布的大致情況

CPU_OCUPATION = read.table(, header=TRUE)
summary(CPU_OCUPATION)

結果如下

看看散點圖

CPU_OCUPATION = read.table(, header=TRUE)
qplot(CPU_OCUPATION$Date, CPU_OCUPATION$Freq) + 
geom_point(colour="red") +
scale_x_continuous(name="date", breaks=seq(0, 90000, by=7200), labels=timeHMS_formatter) + 
scale_y_continuous(name="loop amonunt per second", breaks=seq(0, 36, by=4))

明顯數據處理的粒度太小，看不出什麼有意義的規律

探索每分鍾連續執行循環數量

我們以每分鍾為單位計數一下超時循環執行的次數。

CPU_OCUPATION = read.table(, header=TRUE)
factors.continue_loop.per.min = factor(CPU_OCUPATION$Date)
continue_loop.amount.per.min = tapply(CPU_OCUPATION$Date, factors.continue_loop.per.min, length)
qplot(unique(CPU_OCUPATION$Date), continue_loop.amount.per.min) +
geom_point(colour="red") +
scale_x_continuous(name="date", breaks=seq(19, 1420, by=120), labels=timeHM_formatter) +
scale_y_continuous(name="loop amount per minute", breaks=seq(0, 74, by=3))

得到結果如下，沒有發現和CPU消耗數據相關的特征。比如，考察06:51時刻，CPU消耗100%，但是對應的連續循環數量卻不多。

第二個case：症狀和初步排查

症狀

客戶：

SSD雲盤 IO延時在30ms以上

初步排查

初步排查確定，在客戶的使用方式下，SSD雲盤延遲基本就在30ms左右，並不是突發的異常情況。

進一步溝通後得知，客戶業務高峰時段網絡訪問延遲從原來的30ms左右增至50ms以上，甚至會出現秒級延遲。客戶通過逐行源碼插入print語句，自行排查結論是SSD雲盤IO延遲30ms是致因。

客戶是使用curl工具存取一指定URL來度量訪問延遲的。抓包結果顯示確實有秒級延遲情形出現。那麼，如果在出現問題前在客戶的使用方式下SSD雲盤的延遲就是30ms左右，那麼，SSD雲盤的延遲就不會是致因。因此排查繼續。

根據測試的時間點，檢查係統日誌，一條報警記錄進入了我們的視野

May 27 21:47:40 iZ2zeepzcp7dzdd9e3pe8dZ kernel: TCP: time wait bucket table overflow

相關的測試結果、抓包記錄和日誌報警信息整理如下。但問題是，報警信息和網絡訪問延遲增大有關係嗎？

第二個case：係統日誌排查和結論

此處和處理第一個case的步驟一致，隻是處理邏輯有微調

1. 從係統日誌而非業務日誌獲取數據。
2. 因為問題連續多日出現，因此這裏我們獲取了整個五月份的數據（因為lograte的工作機製，其實是獲取的4周內的數據）。但是我們並不是從05月01日開始製作散點圖的。
3. 因為第2項，R中的時間戳格式化函數也相應做了調整。

按照處理第一個case的步驟，我們可以的到散點圖如下

從散點圖可以看到，從05月23日起，信號開始出現；自05月26日起，連續三日，每日10:30至次日淩晨01:28之間，信號出現。將圖反饋給客戶後，客戶確認散點圖熱點區域出現的時段和延遲出現的時段同步。再結合抓包結果顯示的時間消耗，客戶接受了我們的排查結論。

問題是05月23日客戶作了什麼調整導致問題出現？結論出人意料，客戶答複說05月23日暫時撤除了高防以便使用更穩定帶寬的高防。

更進一步：R在工具化中的位置

由以上兩個case可以看出，排查和診斷過程中，一如在其他數據處理過程中一樣，引入R，使用得當，對於解決疑難雜症，頗見功效。而工具化是共享我們排查技能、流程和知識的合適媒介。因此有必要考察一下R在工具化中的位置。

正如先前已經提到的，排查和診斷過程就是數據處理過程。而R一直是諸如統計學家等數據處理從業者工具箱裏最趁手的工具之一。而且就R支持的功能而言，前麵我們流程中的每一步，均可由R實現。加之R成熟的社區、各種機器學習算法在R中也不乏高質量實現、不斷改進與完善的API以及CRAN（一個R包共享與分發的站點）。因此，我們有理由相信，R或者類似R的組件在工具化中會扮演一個足夠重要的角色。

同樣，以我們前麵給出的流程為例，設想我們要工具化之。比如，以從日誌中搜集可能的致因信號為例。稍加考察你就會發現，我們肯定不是事先在頭腦中記憶了各種可能的係統和業務致因信號後，再進行排查的。比如，第一個case中業務日誌中的超時循環信號，對於不少同學應該都是初次見到。而且一直到解決掉客戶的問題，我們也沒有了解這個日誌記錄在業務邏輯中的意義。以工程師處理過程類比，很明顯，工具化過程中，分類、聚類、預測，這些機器學習的基礎功能模塊，我們都需要。因此，工具化中必定有R或者類似R的組件。

所以，無論是手工排查和診斷，還是更進一步工具化，對於工程師而言，R都是上佳之選。

參考

1. R官方站點
2. 我需要學習R嗎？
3. 服務器診所: 數據處理的利器 R
4. R 和數據世界
5. First-class citizen
6. Google's R Style Guide
7. R (programming language)

最後更新：2017-06-30 11:02:38

  上一篇：  docker私有庫搭建過程（Registry）

  下一篇：  瑞典奶爸“坐月子”很酷，他們的育兒神器連布拉德皮特都在用