拒絕蠻力，高效檢視Linux日誌檔案！

扣釘日記發表於2022-06-24
Linux

原創：扣釘日記（微信公眾號ID：codelogs），歡迎分享，轉載請保留出處。

簡介

日常分析問題時，會頻繁地檢視分析日誌，但如果蠻力去檢視日誌，耗時費力還不一定有效果，因此我總結了在Linux常用的一些日誌檢視技巧，提升日誌閱讀效率。

grep查詢日誌

在我們查詢某些異常日誌時，經常需要同時檢視異常前面或後面的一些日誌，因為有時前面或後面的日誌就已經標識出異常原因了，而grep的-A、-B、-C選項就提供了這種功能，如下：

# 查詢ERROR日誌，以及它的後10行
$ grep -A 10 ERROR app.log

# 查詢ERROR日誌，以及它的前10行
$ grep -B 10 ERROR app.log

# -C代表前10行和後10行
$ grep -C 10 ERROR app.log

檢視某個時間段的日誌

有時，需要檢視某個時間段的日誌，比如凌晨2點15分系統出現報警，上班後我們想看看這段時間的日誌，看能不能找到點線索，方法如下：

# 匯出02:14到02:16分的日誌
awk '/2022-06-24T02:14/,/2022-06-24T02:1[6-9]/' app.log > app0215.log

# 使用sed也是可以的
sed -n '/2022-06-24T02:14/,/2022-06-24T02:1[6-9]/p' app.log > app0215.log

注：awk與sed實際並不解析時間，它們只是按正則匹配，匹配到第一個正則時，開始輸出行，直到遇到第二個正則關閉，所以如果你的日誌中沒有能匹配第二個正則的行，將導致一直輸出到尾行！所以一般需要將第二個正則變寬鬆點，如上面的/2022-06-24T02:1[6-9]/，以避免出現這種情況

檢視最後10條錯誤

更多情況是，上班時發現系統有報警，於是想立馬看看剛剛發生了什麼，即查詢最近的異常日誌，如下：

# 最容易想到的是tail，但有可能最後1000行日誌全是正常日誌
$ tail -n 1000 app.log | less

# 最後10條異常, tac會反向讀取日誌行，然後用grep找到10個異常日誌，再用tac又反向一次就正向了  
$ tac app.log | grep -n -m10 ERROR | tac

還有一種是從剛報警的時間點開始匯出到尾行，比如從2分鐘前的5點15分開始匯出，如下：

$ tac app.log | sed '/2022-06-24T17:15/q' | tac > app1715.log

原理與上面類似，只不過是換成了sed，sed預設會輸出處理的每一行，而q指令代表退出程式，所以上面程式含義是從日誌末尾開始輸出日誌，直到遇到正則/2022-06-24T17:15/停止輸出。

awk分段查詢

對於像Java程式，異常日誌一般會是一段一段的，且每段帶有異常棧，如下：
image_2022-06-24_20220624202645
但grep是一行一行過濾的，如何一整段一整段的過濾異常棧呢？awk就提供了這種功能，當將awk中RS變數指定為空時，awk就會一段一段的讀取並處理文字，如下：

# 查詢異常日誌，並保留異常棧
awk -v RS= -v ORS='\n\n' '/Exception/' app_error.log | less
  1. -v RS=等效於-v RS=''，設定RS變數為空，使得awk一段一段地讀取日誌
  2. -v ORS='\n\n'設定ORS變數為2個換行，使得awk一段一段的輸出
  3. /Exception/代表過濾出包含正則Exception的段

使用less檢視

一般情況下，使用less可以更快速的檢視日誌，比如通過tail -n10000取出最近1w條日誌，通過less檢視，如下：

tail -n 10000 app.log | less

看日誌時，有一個很常見的需求，就是很多日誌都是當前不需要關心的，需要將它們過濾掉，less提供了&/的功能，可快速過濾掉不想看的日誌，從而找到問題日誌，如下：
image_2022-06-25_less_filter2
操作步驟：

  1. 先輸入&，再輸入!進入Non-match過濾模式。
  2. 然後輸入正則netns，再按Enter，排除掉這種正常的日誌，過濾後又發現有很多drop_caches日誌。
  3. 然後也是先輸入&，再輸入!，再直接按上箭頭快速獲取上次的輸入內容，再接著輸入|drop_caches，將drop_caches日誌也過濾掉。
  4. 哦豁，發現了一個oom killer日誌！

使用vim檢視

less可以一行一行的排除，但如果要一段一段的排除，如日誌中經常會有一些常見且無影響的錯誤日誌，這種情況可以通過vim配合awk排除，如下：

tail -n 10000 app_error.log | vim -

image_2022-06-25_vim_filter
操作步驟：

  1. 先輸入:，進入vim的命令模式
  2. 再輸入%!awk -v RS= -v ORS='\n\n' ...，執行awk命令，其中%代表當前檔案所有內容，!代表執行命令，所以%!代表將當前檔案內容輸入到命令中
  3. 然後awk規則中輸入'\!/訂單號不存在/'並回車，這代表排除段中包含訂單號不存在的段，排除後又發現很多沒有找到該暱稱異常。
  4. 接著輸入:再按上箭頭快速獲取上次輸入內容，並補充&& \!/沒有找到該暱稱/，將這種常見異常也過濾掉。
  5. 哦豁，發現了一個NullPointerException異常！

其它工具

有時為節省磁碟空間，日誌會壓縮成*.gz格式，這也是可以直接檢視的，如下：

# 類似cat，同時解壓並輸出內容
zcat app.log.gz  

# 類似grep，同時解壓並查詢內容
zgrep -m 10 ERROR app.log.gz  

# 類似less，同時解壓並檢視內容
zless app.log.gz

而在處理時間方面，dateutils工具包用起來會更方便一些，如下：

# CentOS7安裝dateutils
$ wget https://download-ib01.fedoraproject.org/pub/epel/8/Everything/x86_64/Packages/d/dateutils-0.4.9-1.el8.x86_64.rpm && rpm -Uvh dateutils-0.4.9-1.el8.x86_64.rpm
# Ubuntu安裝dateutils
$ apt install dateutils

# 根據時間範圍過濾日誌，可指定時間串格式
$ cat dmesg.log | dategrep -i '%a %b %d %H:%M:%S %Y' '>=2022-06-24T12:00:00 && <now'
[Fri Jun 24 12:15:36 2022] bash (23610): drop_caches: 3
[Fri Jun 24 13:16:16 2022] bash (30249): drop_caches: 3

# 有時我們需要將日誌中時間串轉換為unix時間綴，方便處理
$ head -n4 access.log
127.0.0.1 - - [07/May/2022:19:00:25 +0800] "GET /health HTTP/1.1" 200 4 3ms "-" "curl/7.29.0" "-" "-"
127.0.0.1 - - [07/May/2022:19:00:26 +0800] "GET /health HTTP/1.1" 200 4 2ms "-" "curl/7.29.0" "-" "-"
127.0.0.1 - - [07/May/2022:19:00:27 +0800] "GET /health HTTP/1.1" 200 4 2ms "-" "curl/7.29.0" "-" "-"
127.0.0.1 - - [07/May/2022:19:00:28 +0800] "GET /health HTTP/1.1" 200 4 2ms "-" "curl/7.29.0" "-" "-"

$ head -n4 access.log |dateconv -i '[%d/%b/%Y:%H:%M:%S %Z]' -f '%s' -z 'Asia/Shanghai' -S
127.0.0.1 - - 1651950025 "GET /health HTTP/1.1" 200 4 3ms "-" "curl/7.29.0" "-" "-"
127.0.0.1 - - 1651950026 "GET /health HTTP/1.1" 200 4 2ms "-" "curl/7.29.0" "-" "-"
127.0.0.1 - - 1651950027 "GET /health HTTP/1.1" 200 4 2ms "-" "curl/7.29.0" "-" "-"
127.0.0.1 - - 1651950028 "GET /health HTTP/1.1" 200 4 2ms "-" "curl/7.29.0" "-" "-"

注：Ubuntu中對命令進行了改名，dategrep叫dateutils.dgrep，dateconv叫dateutils.dconv

總結

這些工具組合起來還是很強大的，這也是為什麼即使在公司有日誌平臺的情況下，依然還是有很多人會去使用命令列！

往期內容

介面偶爾超時，竟又是JVM停頓的鍋！
耗時幾個月，終於找到了JVM停頓十幾秒的原因
mysql的timestamp會存在時區問題？
真正理解可重複讀事務隔離級別
密碼學入門
字元編碼解惑

相關文章