技術文章 » 拒絕蠻力，高效檢視Linux紀錄檔檔案！

拒絕蠻力，高效檢視Linux紀錄檔檔案！

2022-06-25 06:07:54

原創：扣釘日記（微信公眾號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

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

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

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

awk分段查詢

對於像Java程式，異常紀錄檔一般會是一段一段的，且每段帶有異常棧，如下：

但grep是一行一行過濾的，如何一整段一整段的過濾異常棧呢？awk就提供了這種功能，當將awk中RS變數指定為空時，awk就會一段一段的讀取並處理文字，如下：

# 查詢異常紀錄檔，並保留異常棧，-v RS=等效於-v RS=''
awk -v RS= -v ORS='\n\n' '/Exception/' app_error.log | less

使用less檢視

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

tail -n 10000 app.log | less

看紀錄檔時，有一個很常見的需求，就是很多紀錄檔都是當前不需要關心的，需要將它們過濾掉，less提供了&/的功能，可快速過濾掉不想看的紀錄檔，從而找到問題紀錄檔，如下：

操作步驟：

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

使用vim檢視

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

tail -n 10000 app_error.log | vim -


操作步驟：

  1. 先輸入:，進入vim的命令模式
  2. 再輸入%!awk -v RS= ...，執行awk命令，其中%代表當前檔案所有內容，!代表執行命令，所以%!代表將當前檔案內容輸入到命令中
  3. 然後輸入\!/訂單號不存在/，這代表排除段中包含訂單號不存在的段。
  4. 然後又是上箭頭，並補充要排除的段，直到發現感興趣的異常棧即可。

其它工具

有時為節省磁碟空間，紀錄檔會壓縮成*.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會存在時區問題？
真正理解可重複讀事務隔離級別
密碼學入門
字元編碼解惑