• 蘇格團隊
• 作者：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左右，所以是可以忽略不計的。