最近我們介紹了幾款日志分析的工具，比如Scribe和LogStash這類的開(kāi)源項(xiàng)目，以及Splunk這樣的企業(yè)級(jí)工具，還有像SumoLogic和PaperTrail這樣的托管服務(wù)。你可以使用這些工具從海量的日志數(shù)據(jù)提取到一些有價(jià)值的信息。
不過(guò)還有一件事它們是幫不了你的。它們都依賴于你實(shí)際輸出到日志文件里面的數(shù)據(jù)。日志數(shù)據(jù)保質(zhì)保量的重任就落到你肩上了。因此萬(wàn)一情況不妙，你又得在日志文件不全的情況下自己去調(diào)試代碼，那估計(jì)你只好趕緊把原先訂好的晚餐取消掉了。
為了減少出現(xiàn)類似的情況，我這里想分享5點(diǎn)日志打印的心得，希望能對(duì)你有所幫助：
線程名
就像Ringo一樣，線程名應(yīng)該是Java里最被低估的功能之一了。因?yàn)槠鋵?shí)它的表述性很強(qiáng)。那又怎樣？就像我們的名字一樣，我們會(huì)給它賦予一個(gè)含義。
線程名最有用的時(shí)候應(yīng)該就是多線程的情況下了。許多日志框架都會(huì)記錄當(dāng)前方法調(diào)用所在線程的名字。不幸的是，一般看起來(lái)都是這樣的：“http-nio-8080-exec-3″，這是線程池或者容器自動(dòng)分配的線程名。
我經(jīng)常聽(tīng)到有謠傳稱線程名是不可變的。當(dāng)然不是。線程名就是你日志中最優(yōu)質(zhì)的不動(dòng)產(chǎn)，你得確保自己能正確的使用它們。通常給它賦值會(huì)帶上上下文的詳細(xì)信息，比如說(shuō)Servlet或者任務(wù)的名字之類的，以及一些動(dòng)態(tài)的上下文信息比如用戶ID。
這么做的話，你的代碼看起來(lái)應(yīng)該是這樣的：
Thread.currentThread().setName(ProcessTask.class.getName() + “: “+ message.getID);
更高級(jí)的做法是引入一個(gè)ThreadLocal的變量，然后配置一個(gè)appender，自動(dòng)把里面的信息輸出到日志中。
當(dāng)多個(gè)線程同時(shí)在往文件中寫入日志而你需要關(guān)注其中某個(gè)線程的時(shí)候，這個(gè)功能尤其有用。如果你在一個(gè)分布式或者SOA環(huán)境中運(yùn)行的話，這么做還會(huì)有一個(gè)額外的好處，下面我們很快就會(huì)看到。
分布式標(biāo)識(shí)符
在SOA或者消息驅(qū)動(dòng)的架構(gòu)中，某個(gè)任務(wù)的執(zhí)行可能會(huì)涉及到多臺(tái)機(jī)器。這種架構(gòu)下如果出了錯(cuò)要進(jìn)行處理的話，要想知道到底發(fā)生了什么，這里所牽涉到的相關(guān)機(jī)器以及它們的狀態(tài)就顯得至關(guān)重要。很多日志分析器只是幫你把這些日志收集起來(lái)，它們假設(shè)你已經(jīng)有一個(gè)唯一的標(biāo)志符，可以用它來(lái)進(jìn)行過(guò)濾。
從設(shè)計(jì)的角度來(lái)看，這意味著系統(tǒng)中每一個(gè)入站操作都需要有一個(gè)唯一的ID，處理過(guò)程中會(huì)一直攜帶著這個(gè)ID直到處理結(jié)束。這里如果使用持久性標(biāo)識(shí)比如說(shuō)用戶ID之類的可能并不適合，因?yàn)樵谝粋€(gè)日志文件中一個(gè)用戶可能會(huì)有多個(gè)請(qǐng)求在同時(shí)進(jìn)行處理，這就很難提取出具體的某個(gè)處理流。UUID是個(gè)不錯(cuò)的選擇，你可以把它存儲(chǔ)到線程名或者TLS——ThreadLocal Storage里面。
不要使用循環(huán)
你經(jīng)常會(huì)看到有在循環(huán)體中進(jìn)行日志打印，這么做的前提是循環(huán)的次數(shù)是有限的。
如果不出什么問(wèn)題的話當(dāng)然還好。不過(guò)如果代碼碰到一些異常的輸入導(dǎo)致循環(huán)無(wú)法退出的話，這就不妙了。這可不止是循環(huán)無(wú)法結(jié)束的問(wèn)題了，你的程序還一直在往磁盤或者網(wǎng)絡(luò)中寫入數(shù)據(jù)。
如果只是寫到自己的設(shè)備中，結(jié)果可能就只是掛了一臺(tái)服務(wù)器，但如果是一個(gè)分布式的環(huán)境，就可能就是一整個(gè)集群都癱了。所以最好還是不要在循環(huán)里面打印日志，尤其是當(dāng)涉及到異常處理的時(shí)候。
我們來(lái)看一個(gè)例子，這里是在循環(huán)中來(lái)打印異常的信息：
void read() { while (hasNext()){ try { readData(); } catch {Exception e) { // this isn’t recommend logger.error(“error reading data“, e); } } }
如果readData()拋出異常并且hasNext()返回true，這段代碼就會(huì)不停在打印日志。一個(gè)解決方法就是不要每次都打印出來(lái)：
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. } } } }
還有一個(gè)方法就是把日志操作從循環(huán)中去掉，在另外的地方進(jìn)行打印，只記錄第一個(gè)或者最后一個(gè)異常就好了。
未捕獲的異常
維斯特洛有一道最后的防御墻，而你有Thread.uncaughtExceptionHandler。請(qǐng)確認(rèn)你已經(jīng)用上它們了。如果沒(méi)有的話，你的異常可能這么沒(méi)了，而你只能拿到很少的一些上下文信息，同時(shí)這些異常在哪打印，是否打印，你也不好控制。
如果你的代碼出現(xiàn)異常卻沒(méi)有記錄下來(lái)，或者記錄下來(lái)了卻沒(méi)有相關(guān)的狀態(tài)信息，那真是非常失敗。
盡管在uncaughtExceptionHandler里面看似已經(jīng)訪問(wèn)不了線程里面的任何變量了（它已經(jīng)掛了），但你至少還有一個(gè)當(dāng)前線程的引用。如果結(jié)合剛才提到的第一條建議的話，至少日志中還能打印出一個(gè)有意義的thread.getName()的值。
捕獲外部調(diào)用的異常
只要你調(diào)用到了JVM以外的接口，那么發(fā)生異常的概率就大大提升了。這包括WEB服務(wù)，HTTP,數(shù)據(jù)庫(kù)，文件系統(tǒng)，操作系統(tǒng)或者其它的一些JNI調(diào)用。你得把每一個(gè)調(diào)用都當(dāng)成一個(gè)定時(shí)炸彈來(lái)處理。
大多數(shù)情況下，外部調(diào)用之所以會(huì)失敗是因?yàn)閭魅肓隋e(cuò)誤的參數(shù)。為了修復(fù)這些問(wèn)題，把這些請(qǐng)求參數(shù)記錄到日志中是非常有必要的。
你可能不想記錄錯(cuò)誤信息，而是直接去拋出異常，這樣做也沒(méi)有問(wèn)題。不過(guò)這么做的話，你要盡可能把相關(guān)的參數(shù)都收集起來(lái)，放到異常信息里面去。
你得確保在上一層調(diào)用中捕獲了異常并且記錄到了日志里。
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); //這里你也可以拋出一個(gè)異常，記得把ERR信息帶上。 }
原文地址：http://it.deepinmind.com/java/2014/05/03/5-techniques-2-improve-your-server-logging.html
