- 蘇格團隊
- 作者:MaxPan
- 交流QQ群:855833773
背景
在自定義Egg.js的請求級別日誌這篇文章中,我們實現了自定義請求級別的日誌模組。看上去功能是完整了,但好像還缺點什麼。
大家在根據日誌追查問題的過程中,很多時候看到了某條log資訊想去找出處,但是實際上程式碼裡面打相同型別的log地方可能不止一處,這時你就比較難去定位這行log到底是哪裡打的。
舉個最極端的例子
//home.js
class AppController extends app.Controller {
async first() {
this.ctx.swLog.info('in controller');
await this.ctx.render('first.html');
}
async second(){
this.ctx.swLog.info('in controller')
await this.ctx.render('second.html');
}
}
複製程式碼
上面的例子雖然比較極端,但是我們在程式碼中難免會碰到類似的情況。兩個route對於的controller中都列印了相同的log,你在查日誌的時候,是無法區分log到底是first裡面打的還是second裡面打的。
這個時候,我們就需要在日誌列印的時候,同時也將呼叫日誌時的檔名和程式碼行數記錄下來一併列印,效果如下
[2018-11-02 19:25:09.665][22896][home.js:4][/] in controller
複製程式碼
開始動手
查了很久的Nodejs文件,發現Nodejs的api中並沒有直接提供我們想到的資訊,所以只能另找出路。
回憶我們以往的開發,這類的資訊好像只有在Nodejs丟擲異常的時候看到過。每當Nodejs丟擲異常時,我們都能看到一堆異常呼叫的堆疊,裡面就有我們想要的資訊,我們從這開始入手。
我們先手動創造一個異常物件,並列印出來
function getException() {
try {
throw Error('');
} catch (err) {
return err;
}
}
let err = getException();
console.log(err);
複製程式碼
console的資訊如下圖:
在圖上我們可以看到,我們想要的資訊
err物件在console的時候,會直接輸出err物件中的stack屬性,該屬性是個字串,我們可以通過一系列的字串操作,拿到我們想要的檔名和行數。
接下來我們開始對日誌模組程式碼進行改造,新增一個getCallerFileNameAndLine方法,如下:
getCallerFileNameAndLine(){
function getException() {
try {
throw Error('');
} catch (err) {
return err;
}
}
const err = getException();
const stack = err.stack;
const stackArr = stack.split('\n');
let callerLogIndex = 0;
for (let i = 0; i < stackArr.length; i++) {
if (stackArr[i].indexOf('Map.Logger') > 0 && i + 1 < stackArr.length) {
callerLogIndex = i + 1;
break;
}
}
if (callerLogIndex !== 0) {
const callerStackLine = stackArr[callerLogIndex];
return `[${callerStackLine.substring(callerStackLine.lastIndexOf(path.sep) + 1, callerStackLine.lastIndexOf(':'))}]`;
} else {
return '[-]';
}
}
複製程式碼
最終結果
最後我們每條列印的日誌後面,都會跟上檔名和行數
有的同學可能擔心,每次打log都拋一個異常,會不會對效能造成影響。
我在getCallerFileNameAndLine
方法前後進行打點統計,平均執行時間在2ms
左右,所以是可以忽略不計的。