提高日誌質量的 5 大技巧

OneAPM官方技術部落格發表於2015-07-09

最近湧現出各種各樣能幫助你理解日誌的新工具,有類似 Scribe、Logstash 這樣的開源專案,也有類似 Splunk 的預付費工具,還有託管服務如 SumoLogic 和 PaperTrail。這些工具的共同點是對日誌資料進行清洗,在大量日誌中提取一些更有價值的檔案。

提高日誌質量的五大技巧

但有一件事這些工具卻愛莫能助,因為它們完全依賴你實際投入的日誌資料,而如何保證資料的質量和數量則需要使用者自行完成。因此,在關鍵時刻,如果你需要基於部分或者遺漏日誌做程式碼除錯時,事情可能會變得非常棘手。

為了減少這種情況發生,在這裡分享五個建議,在你記錄日誌時最好能銘記於心:

1. 你好,我的(執行緒)名字是

正如 Ringo,執行緒名稱這個屬性是 Java 中最被低估的方法之一。其原因是執行緒名稱大部分是描述性的。然而問題同樣出現在這裡,類似人們自己,起名時通常會被賦予一定的意義。而在多執行緒日誌中,執行緒名同樣揮著關鍵作用。通常情況下,大多數日誌框架會記錄當前所呼叫的執行緒名稱。可悲的是,我們通常會看到 http-nio-8080-exec-3 這種名字,簡單地由執行緒池或容器進行分配。

出於某種原因,我們曾不止一次地聽過這種誤解——執行緒名稱是不可變的。與之相反,在日誌中,執行緒名稱佔據基本主要地位,你應該確保能正確使用。比如將它與具體情境結合起來,例如 Servlet 的名字、任務相關,或者一些動態語境如使用者或訊息 ID。

這樣的話,程式碼介面應該是這樣:

Thread.currentThread().setName(ProcessTask.class.getName() + “: “+ message.getID);

更先進的版本將被載入到當前執行緒的執行緒區域性變數,配置 log appender,並自動將其新增到日誌條目。

當多個執行緒寫入伺服器日誌,但你需要集中在單一執行緒上時,這將會非常有用。如果你在一個分散式 /SOA 環境下執行,更能看到它得天獨厚的優勢。

2. 分散式的識別符號

在 SOA 或訊息驅動的架構,任務執行很可能跨多臺機器。當處理這種環境下的故障時,連線相關機器和它們的狀態將是瞭解具體情況的關鍵。大多數日誌分析器會將這些日誌資訊分組,假設你為它們提供了唯一標識,它們便可以作為實際日誌訊息的一部分。

從設計的角度出發,這意味著,從進入系統到操作完成,每一個入站操作應該有其唯一的 ID 對應。請注意,一個持久的識別符號,如使用者 ID 可能不是一個好容器。在記錄日誌檔案的過程中,使用者可能有多個操作,這將使得隔離特定流更加困難。UUIDs 可能是個不錯的選擇。它的值可以被載入到實際執行緒名稱或者作為 TLS-thread 的區域性儲存器。

3. 不要使用文字+驅動器,不要日誌+迴圈

很多時候,你會看到一段程式碼在緊密的迴圈中執行,並執行相應的日誌操作。基本假設是,該程式碼執行的次數是有限的。

很可能執行情況非常良好。但是當程式碼得到意外輸入時,迴圈可能並不會中斷。在這種情況下,你不只是處理一個無限迴圈「雖然這樣已經很糟糕了」,你正在處理的程式碼正將無限量的資料寫到磁碟或網路。

在單機場景中它可能會造成一臺伺服器崩潰,而在分散式場景中,被影響的則是整個叢集。因此如果可能,不要在緊密迴圈中記錄日誌。捕獲錯誤時,這一點尤其如此。

下面這個例子,記錄了一個 while 迴圈中的異常:

void read() {
while (hasNext()) {  
try {  
readData();  
} catch {Exception e) {
// this isn’t recommend
logger.error(“error reading data“, e);  
}
}
}

如果 readData 丟擲異常,而 hasNext 返回值為 true,這裡將會寫入無限量的日誌資料。要解決這個問題的方法是確保不會記錄這一切:

void read() {  
int exceptionsThrown = 0;  
while (hasNext()) {  
try {  
readData();  
} catch {Exception e) {
if (exceptionsThrown < THRESHOLD) {  
logger.error(“error reading data", e);  
exceptionsThrown++;  
} else {
// Now the error won’t choke the system.
}
}
}
}

另一種方法是從迴圈中移除日誌記錄,並儲存第一/最後一個異常物件並在其它地方記錄。

4. 未捕獲的處理程式

Westeros 有最後一道防禦牆,而你有 Thread.uncaughtExceptionHandler。因此,儘量使用它們。如果沒有安裝這些處理程式,在異常丟擲時,你只能獲得很少有價值的上下文,同時你也無法控制在結束之前你已經將其記錄,並確定記錄的位置。

請注意,即使在未捕獲的異常處理程式,看起來你沒有任何辦法訪問執行緒中(已終止)的任何變數,你仍然可以獲得實際執行緒物件的引用。如果你堅持# 1步,你仍然會得到一個有意義的thread.getName()值可記錄。

5. 捕獲外部呼叫

每當呼叫一個外部的 API, JVM 異常的機率將大大增加。這包括 Web 服務、 HTTP、 DB、 檔案系統、作業系統和任何其他 JNI 呼叫。認真對待每個呼叫,因為它隨時會爆炸 「它很有可能發生在同樣的點」。

大多數情況下,外部 API 故障的原因是意外輸入,日誌中對其記錄是修復程式碼的關鍵。

在這一點上,你可以選擇不記錄錯誤,只是丟擲異常也可以。在這種情況下,只要收集到呼叫的相關引數,並將其解析為異常錯誤資訊。

只要確保異常被捕獲並記錄在更高階別的堆疊呼叫即可。

try {  
return s3client.generatePresignedUrl(request);  
} catch (Exception e) {
String err = String.format(“Error generating request: %s bucket: %s key: %s. method: %s", request, bucket, path, method);  
log.error(err, e); //you can also throw a nested exception here with err instead.  
}

相關文章