前言
日誌是開發者用來分析程式和排查問題的重要工具。隨著系統架構從早期的單體應用，演變到如今的微服務架構，日誌的重要性也逐步提升。除了用日誌輔助問題排查，還可以通過日誌對微服務請求的全鏈路進行效能分析，甚至可以它用來解決分散式系統中的一致性問題。與此同時，系統產生的日誌量和日誌管理難度也顯著增加。於是，日誌管理工具隨之誕生並迭代升級。從最開始登入到跳板機上檢視日誌，到自建分散式日誌中心來統一管理日誌流，到雲平臺廠商提供專門的日誌管理服務。開發者只需要在應用中接入SDK將日誌迴流到日誌平臺，就可以使用日誌平臺提供智慧檢索、資料分析以及鏈路分析等能力，平臺中易用的圖形化介面和成熟的資料管理能力極大的提升了開發效率。
但是，日誌管理平臺並不是萬能的，總有一些場景它會缺席（如本地除錯產生的日誌並不會迴流到日誌平臺，不支援複雜的資料分析，當然還有最常見也是最令人崩潰的，資料丟失了。。。），而我們不得不和一大堆原始日誌檔案面面相覷。這時我們就不得不從工具包中掏出原始的武器-linux指令，開始一頓操作猛如虎。
本文將結合自己在日常開發過程中遇到的場景給出對應的日誌檢索語句，也歡迎大家將它收藏到自己的工具包中，或是在下方留言自己遇到的日誌分析難題，博主會將其完善到文章中。
日誌結構
在瞭解到日誌分析語句之前，先簡單介紹一下日誌的型別和結構，後序將以這一節介紹的內容作為背景提供具體的日誌分析語句。
日誌型別主要有兩種，一種是業務日誌，即實現業務功能的過程中產生的日誌，通常是開發者在程式中主動埋點觸發的。還有一種是系統日誌，這一類日誌範圍更大，底下還可以繼續細分，如系統所在的宿主機各項指標的快照，或者是依賴的中介軟體內部列印的日誌等。
業務日誌和系統日誌通常在不同的目錄下，事實上，不同型別的系統日誌一般也會用獨立的目錄進行隔離。以一個接入了Mysql，RocketMq的系統為例，它的日誌目錄結構可能如下所示：
/log
/mysql
/rocketmq
/app
/app_name1
/app_name2可見，app下不同的業務系統之間也會進行日誌隔離，方便檢索和檢視。
接著看一下每個目錄下日誌檔案的結構，這個往往沒有絕對的標準，開發者通常按照系統的需要設計日誌檔案結構，甚至產生指定用途的日誌（如mysql的bin log和relay log）。這裡簡單介紹一下我進行系統開發時習慣的日誌結構設計。
通常我至少會區分出三個日誌檔案: application.log, application-error.log和application-warn.log。正如檔案的名稱所示，它們分別對應不同級別的日誌，application.log中會包含應用生命週期中的全部日誌，而application-error.log和application-warn.log日誌則分別只記錄error級別日誌和warn級別日誌，從而方便快速定位系統異常。但是，如果你直接檢視目錄下的所有日誌檔案，會發現它不止有這三個檔案.
這是因為系統執行過程中會產生大量的日誌，如果只用一個檔案進行日誌的儲存，會導致檔案變得極為龐大並嚴重消耗磁碟空間。因此，作業系統或是日誌工具在經過配置後會執行日誌截斷，壓縮和備份等操作，減少日誌對整個宿主機穩定性的影響。被截斷後的日誌會根據配置在日誌名加上字尾並儲存，通常是加上時間戳。
除了上文所示的根據日誌級別來劃分多個日誌檔案，還可以從別的維度設計日誌檔案，比如將系統流量的入口和出口分別列印日誌。流量的入口可以理解為RPC介面Server端，HTTP服務Server端，MQ接收訊息日誌等，與之相對的流量的出口是指RPC介面Client端，呼叫下游HTTP服務等。因此整個日誌目錄將會包含以下幾個檔案
application.log
appilcation-error.log
application-warn.log
rpc-client.log
rpc-server.log
mq.log具體的日誌配置不在本文的範圍內，大家可以自行閱讀logback等日誌框架的文件。
日誌分析小操作
接下來將會列出在日常開發過程中常見的日誌查詢和分析場景，並給出對應的指令。
檢視日誌
檢視單個日誌檔案
cat是我們最常用的閱讀檔案的指令，通過cat ${filename}即可展示檔案的內容。以application.log為例cat application.log這個指令適用於檢視所有可讀檔案。
檢視多個日誌檔案
上文提到，因為Logrotate機制的存在，日誌檔案往往會被截斷成多個帶有不同時間戳字尾的檔案，而我們又不確定想要查詢的日誌具體在哪個檔案中，這時候可以將多個檔案都傳給cat指令，cat ${filename} ${filename2} ${filename...}，cat會逐個讀取檔案並展示。但是如果檔案數量非常大呢？幸好cat指令支援類似正則的匹配，*關鍵字允許我們匹配任意多個欄位。cat application1.log application2.log application3.log cat application.log*當然，在檔案數量很多的時候用cat指令檢視全量日誌已經不是很好的選擇了，下文將會給出其它日誌查詢方法。
檢視最後幾行日誌
cat指令會將整個日誌檔案從頭到尾讀取並展示在控制檯，但是有時我們往往只需要看最近一段時間的日誌即可。而且在日誌檔案特別大的時候，用cat指令不僅比較慢，而且會導致大量無關的日誌充斥螢幕影響閱讀。這時用tail指令就可以很好的解決這個問題。tail指令可以只讀取日誌最後幾行內容並展示在螢幕上。tail application.log # 讀取application.log檔案最後一部分日誌tail指令同樣支援傳入多個檔案，它會按照順序分別讀取幾個檔案的最後一部分內容並列印到控制檯
tail application1.log application2.log application3.log如果想要指定展示最後100行的日誌，則可以使用
tail -n來配合查詢：tail -n 100 application.log檢視增量日誌
有時，我們希望實時檢視日誌檔案的內容，從而更快速的捕捉到系統的行為，tail -f指令則支援動態的展示檔案新增的內容。如果想要退出自動重新整理，可以通過ctrl+c指令來實現：tail -f application.log分頁檢視日誌
有時，因為日誌內容實在太多，導致控制檯瘋狂輸出，直接淹沒了關鍵資訊。因此，需要一個指令能夠分頁檢視日誌內容，降低控制檯重新整理的頻率。more指令為這個場景提供了非常好的支援。more application.log執行了more指令後，控制檯將會逐屏展示檔案內容，可以使用空格(space鍵)來展示下一屏的內容，回車（Enter鍵）展示下一行的內容，Q鍵退出more指令
至此，檔案的全文查詢和部分查詢的主要指令已經給出，下面給出另一種型別查詢，根據關鍵字查詢，的相關指令
關鍵字檢索
根據關鍵字檢索日誌
在分散式系統中，往往會有數十甚至數百個系統參與到流程中，這時流量的入口會生成一個唯一的logId用來串聯和標記全鏈路請求。當我們需要上下游排查問題時，往往會將logId提供給對方來排查。同樣，當我們拿到logId時也需要從日誌中跟該logId有關聯的日誌內容查詢出來。這就是一個典型的根據關鍵字檢索日誌的場景。
grep指令很好的解決了這個問題，它能夠將日誌中和關鍵字匹配的行列印出來。grep "logId" application.log上面的指令會將application.log檔案中所有包含logId的行列印出來。
grep指令同樣支援多檔案查詢grep "logId" application1.log application2.log application3.log grep "logId" application*.log還有正規表示式的匹配或者是大小寫不敏感的匹配
grep "logId" application.log -i # 大小寫不敏感 grep -E "[\w\d]*" application.log # 正規表示式
這裡順便提醒一個系統設計的注意點，在分散式系統中logId是通過寫入當前執行緒上下文中實現傳遞，因此如果在當前執行緒中提交了一部分任務給非同步執行緒執行，同時有希望能夠用當前執行緒來跟蹤，則務必記得將logId傳遞到非同步執行緒的上下文中。
檢視關鍵字附近日誌
不知道大家在程式中是否寫過這樣的日誌邏輯：log.error("something went wrong keyId:{}", keyId, ex)。通過這一行日誌，我們期望將異常的關鍵id和堆疊在日誌中打出來。但是，日誌系統會將這一行日誌和堆疊分為兩行進行列印。如果直接使用grep ${keyId} application.log，則無法查詢到下一行的堆疊資訊。因此，我們需要檢視這個關鍵字行附近的N行的日誌幫助我們快速定位異常原因。grep也提供了這個能力：grep 'something went wrong' -A 100 application.log上面這行語句展示了
something went wrong這一行日誌後100行的日誌，包括命中的這一行。這裡-A是--after-context的縮寫，方便記憶。
同理，也可以檢視匹配行前N行的日誌：grep -B 100 application.log這裡
-B是--before-context的縮寫。當然，這兩個指令也可以一起使用~多關鍵字查詢
有時我們並不一定能夠拿到請求的logId，可能只有呼叫方法以及方法中的關鍵傳參，如果只根據方法名稱進行匹配，則可能查出許多無關的呼叫，反之只用關鍵傳參查詢也是，這個引數可能呼叫了許多別的方法，這些日誌都將影響我們找到正確的關鍵性請求。grep同樣提供了多關鍵字匹配的模式，假設我們現在有一個方法叫做helloWorld(String name)，並傳入了值ralegrep -e "helloWorld" -e "rale" application.log但是這個指令並不匹配這個場景的訴求，因為它實際上是一個或關係，即包含helloWorld或是rale的日誌行都會被過濾出來。這裡就要引入linux的管道操作(pipeline)。linux的管道操作符
|可以將兩個shell指令串聯起來，其中前一個指令的Output將會是下一個指令的Input。grep -e "helloWorld" application.log | grep "rale"正如上面的指令所示，第一條grep語句將會過濾出所有包含helloWorld的日誌行並傳遞給下一個指令，第二條grep指令則會在這個基礎上在過濾出包含rale的日誌行。這就構成了一個AND關係，符合我們的要求。
反向查詢（正向查詢+反向查詢）
有時，我們可能希望反向查詢日誌，即查出不包含某些關鍵字的日誌，這通常適用於問題更模糊的場景。舉個例子，現在有使用者提出客訴，說某一個功能出現了異常，但是作為中颱服務我們往往很難立刻定位具體是哪個方法或是哪個服務出現問題，因此就會先將這個使用者（假設有uid）的所有請求列印出來並過濾掉結果正常的方法。這裡可以結合上面的管道指令一起使用。grep "$uid" application.log | grep -v "SUCCESS"-v是--revert-match的縮寫，這裡會先找出uid的所有日誌，並過濾掉結果為成功SUCCESS的呼叫。- 檢視時間區間內的日誌
問題排查時能夠獲得的資訊只有更少沒有最少，導致日誌的查詢只有更秀沒有最秀。使用者在反饋問題時，有時只能給到我們時間發生的大概時間，其它任何資訊都沒有。因此我們需要查詢這一時間區間內的所有入口呼叫並結合上面的反向查詢逐漸過濾出真正需要關心的內容。這裡假設每一行日誌中都有時間戳資訊。
有多種方法可以實現，首先可以是用我們之前講到的grep正則匹配模式：
grep -E '2021-10-02 19:\d\d:\d\d:' application.log這裡用正規表示式的方式匹配出2021年十月二號19點的所有日誌，同理，如果想要精確到時分秒，則將對應位上的表示式改為具體的數值即可。這種方式有一個比較明顯的缺點，即靈活度不夠，假如我們需要查詢出晚上19:58到20:02的資料，正規表示式就很難滿足。
因此我們需要一個新的指令來完成這個使命: sed。
sed是一個流編輯器，相對於grep來說能夠支援更加複雜的指令，和對檔案的編輯。這裡僅提供針對時間範圍日誌查詢的語句，其它功能大家可以做一些擴充套件閱讀：
sed -n '/2021-10-02 19:58:00/,/2021-10-02 20:02:00/p' application.log-n會過濾出匹配的行，p代表列印到控制檯。再看一下-n後緊跟的內容，這裡,代表範圍查詢，這個範圍可以是行號，也可以是正規表示式，或者是兩個的結合。示例中給出的是精準匹配。範圍查詢的規則是會找到所有滿足的區間都列印出，比如假如範圍是/a/,/z/，則sed會順序找出所有滿足開始行包含a結束行包含z的區間。每找到一個a~z的區間，sed就開始找下一個包含a的行，找到後再找包含z的行直到檔案結束。
這種查詢方式在日誌存在亂序的場景下會比較不利，如20:00的日誌在20:02之後出現，則它可能無法被過濾出來。同理，如果日誌中19:58:00和20:02:00這兩個時間點恰巧沒有日誌，也可能會導致無法過濾出正確的內容。因此我們通常需要先列印出部分日誌得到有日誌行的時間戳，再用這個時間戳進行過濾。
高亮關鍵字
這裡針對grep指令給出一個提高可讀性的option，即高亮關鍵字，從而更快的定位日誌行。grep "logId" application.log --color=auto
分類/排序
上文中給出了查詢日誌行的指令，下面我們將討論一些常見的日誌統計和分析的操作。以下的大部分操作日誌平臺都可以提供，但是不排除有時我們需要手撕一份日誌檔案。
統計關鍵字出現的次數
這個場景其實我在開發過程中真實遇到過。當時出現了一些線上問題，需要統計究竟有多少比例的流量受到影響。統計的指標就是根據方法關鍵字+執行結果為失敗代表受到系統異常影響的請求。因為資料量也已經超過了單次查詢的最大行數上限，因此最終是將機器上的日誌檔案下載下來自己統計。
這時，就要提到一個新的指令wc:grep "methodName" application.log* | grep "FAIL" | wc -l這裡的兩個grep指令會幫我們過濾出失敗的請求，wc指令會對輸入流進行統計，統計的內容可以包括位元組數，行數或是字元數。這裡
-l指令表示只展示行數。
假如統計維度升級，我們希望統計有多少的使用者受到影響（日誌中包含使用者的uid），這時單純的統計行數就會產生重複統計。因此我們需要根據使用者id對日誌行進行去重。這裡又要引入一個新指令uniq，它可以對整行或者是根據行內的部分資訊進行去重，並統計每一個關鍵字關聯的行數。這裡要注意，uniq僅對排序後的行生效，因此還需要將關鍵字擷取、排序後再使用uniq才能達到預期效果
grep "methodName" application.log* | grep "FAIL" | cut -d ' ' -f 1 | sort | uniq -c這裡又冒出了一堆新的shell指令，首先是cut指令，cut指令會根據指定規則將對應位上的值複製到輸出流中，類似於電腦上的ctrl+c。-d宣告瞭切割日誌行的分隔符，這裡按照空格對行進行切割。-f則指定取哪一個位置上的值，cut指令後生成的字串列表是以1作為起始下標的，因此這裡取了分割後的第一個字串（假設日誌格式為userId timestamp threadId ....，當然大多數情況下userId並不會是行首的內容）。接著對所有userId進行排序，這裡使用了sort指令。最後用uniq指令去重，-c選項是指在每列旁邊顯示該行重複出現的次數。
匯出結果
假設現在我希望將上面的統計結果匯出到檔案中並傳給別人，linux管道同樣支援將輸出流重定向到檔案中...a lot of command ... > result.txt這裡txt檔案只是一種示例，你可以宣告其它格式的檔案。
逆向思維-列印日誌最佳實踐
在上文介紹了一些日誌解析和統計的方式後，也反過來想我們在系統中列印日誌時的一些實踐。日誌格式的統一化往往可以讓我們更快速的根據日誌完成一系列的統計分析。目前主流的日誌格式通常如下：
%level %d{yyyy-MM-dd HH:mm:ss.SSS} %F:%L %X{HOST_IP:-_} %X{LOG_ID:-_} %X{CLUSTER:-_} %X{STAGE:-_} [%t] %m%n%wEx -->可以看到其中會包含日誌級別，分散式logId，時間戳，宿主機關鍵資訊（ip，環境），執行緒id等。同樣的，我們在業務系統中列印的日誌如果也能遵循一定的格式，也會極大增強日誌排查的可讀性和方便性。比如，在列印RPC Server端日誌時，我通常會給出三類日誌，Start日誌，Finish日誌和Digest日誌。
private static final String START_LOG_TEMPLATE = "[rpc_server_start] [method]:{} [request]:{}";
private static final String FINISH_LOG_TEMPLATE = "[rpc_server_finish] [method]:{} [success]:{} [duration]:{}s [request]:{} [result]:{}";
private static final String DIGEST_LOG_TEMPLATE = "[rpc_server_digest] [method]:{} [success]:{} [duration]:{}s";其中Start日誌是請求開始處理前列印，包含入參，呼叫方等資訊，Finish日誌則是列印入參，出參，是否成功以及耗時。Digest日誌較為特殊，它不包含呼叫的任何請求響應資訊，它只會列印出呼叫的方法，是否成功，耗時等資訊。通常會使用Digest日誌來進行快速的效能分析。
小結
本文講的日誌操作只是整個日誌檔案處理操作中的冰山一角，卻一定是最常見也是最有可能用到的，希望對大家有所幫助。也歡迎大家將它收藏到自己的工具包中，或是在下方留言自己遇到的日誌分析難題，博主會將其完善到文章中。