iT邦幫忙

2018 iT 邦幫忙鐵人賽
DAY 15
0
自我挑戰組

花式PHP系列 第 16

Laravel:深入Log

本篇文章因為有相當大的篇幅在追蹤原始碼,並且把對應的篇幅以連結的方式提供。
請善用「Ctrl+點擊」的方式在新的分頁打開連結

這篇文章的重點在於研究 Log 時發生的行為,以及日誌等級在 Log 中扮演的角色。
所以並不會面面具到的談 monolog 的深度運用如各種 handlers 及 processors

重點

  1. 日誌(Log)分成八個各自有其意義的等級(Level),低到高:
    1. debug
    2. info
    3. notice
    4. warning
    5. error
    6. critical
    7. alert
    8. emergency
  2. 日誌記錄器(Handler)預設的等級是 debug
  3. 日誌記錄器只會紀錄比自身設定的等級還高的訊息(example: emergency > notice)
  4. 沒設定任何日誌記錄器時,Monolog 會向 php://stderr 傳遞錯誤訊息

Illuminate\Log\Writer

Illuminate\Log 底下的檔案很少,
所以很簡單就能發現所有 Log::info 之類的實作都是寫在 Writer 這個 class。

一般我們都是使用如 Log::info()Log::critical() 作為程式的進入點,
所以我們也從這隻檔案的這些函式看起。
source code
其實看起來它們的結構也高度的相似,都是把自身的參數在傳遞給 writeLog() 執行。

writeLog()

source code

這邊開始有點不一樣了!

首先它會先把 $message 丟進 $this->formatMessage() 作處理之後,
再把所有參數都傳給 $this->fireLogEvent()
然後再一次把所有參數傳給 $this->monolog->{$level}()

fireLogEvent()

source code

這邊發生的事情大概大家看註解也心理有個底吧?

這邊 Laravel 會把現在這筆訊息再傳遞給 Laravel 自己的 Event/Listener 系統,
所以如果大家有使用過 barryvdh/laravel-debugbar 的話,
應該也曾注意到透過 Log 紀錄的訊息也會在 debugbar 中出現吧?
背後的魔法就發生在這~

monolog->{$level}()

真正透過 monolog 作紀錄還是要看這邊在必瞎咪莽~

大家注意到了吧?
在這一系列的 logging class 中,似乎日誌等級總是不可或缺的元素,
在這邊甚至把它當成 function name 了呢!

所以我們可以預期到如果我們往下追蹤 Writer 中的 monolog 實例,
其中應該也會有與八個日誌等級同名的函式!

Monolog\Logger

source code

果然找到了!而且它們的結構也與 Illuminate\Log\Writer 中的函式們驚人的相似!
Illuminate\Log\Writer 畢竟只是 Monolog\Logger 的包裝,
所以除了這八個函式之外的其他函式作的事情還是不一樣的。

比如說 Monolog 因為接受使用各種不同的日誌記錄器來紀錄,
所以這個 class 便有下列這些增減日誌記錄器的函式:

  • pushHandler()
  • popHandler()
  • setHandlers()
  • getHandlers()

但我主要想了解的還是 Log 被記錄下來的行為,
所以接下來便從八個日誌等級的函式都有呼叫到的 addRecord() 繼續研究!

addRecord()

source code

底下這段的意思是:
從已註冊的 handlers 中找到可以處理目前這筆訊息的 handler,
並在找到第一個符合條件的 handler 時中斷迴圈。

可不可以處理與否端看 handler 設定的等級與這筆訊息的等級

如果沒找到半個,那就直接用 return false; 停止紀錄。

<?php

// check if any handler will handle this message so we can return early and save cycles
$handlerKey = null;
foreach ($this->handlers as $key => $handler) {
    if ($handler->isHandling(['level' => $level])) {
        $handlerKey = $key;
        break;
    }
}
if (null === $handlerKey) {
    return false;
}

下面這段就是在準備 handler 需要的各項資料,
並透過註冊好的 processors 對資料作額外的修改。

<?php

$levelName = static::getLevelName($level);
$record = [
    'message' => $message,
    'context' => $context,
    'level' => $level,
    'level_name' => $levelName,
    'channel' => $this->name,
    'datetime' => new DateTimeImmutable($this->microsecondTimestamps, $this->timezone),
    'extra' => [],
];
foreach ($this->processors as $processor) {
    $record = call_user_func($processor, $record);
}

接下來這段的用意首先是透過第一段程式碼紀錄的 $handlerKey 找到該 handler。
再來就是把準備好的資料,塞給剛剛找到的 handler 處理。

但其中第二個迴圈(也就是上面這句話發生的地方)中斷的條件是,
該 handler 已經執行 handle() 並回傳 TRUE

也就是說只要有一個 handler 記錄下來這筆訊息就足夠了。
除非它失敗了,那麼這個迴圈便會要求在它後面的一個 handler 承接處理這筆訊息。

<?php

// advance the array pointer to the first handler that will handle this record
reset($this->handlers);
while ($handlerKey !== key($this->handlers)) {
            next($this->handlers);
}
while ($handler = current($this->handlers)) {
    if (true === $handler->handle($record)) {
        break;
    }
    next($this->handlers);
}
return true;

到這邊 Log 的行為已經大致上都知道了,
不過為了確定細節,我想繼續往 $handler->isHandling() 裡面探索看看

Monolog\Handler\AbstractHandler

這個 class 是所有 handlers 的亞當兼夏娃,
所以如果一個 handler class 沒有複寫 isHandling() 這個函式,
那麼便會依循這個 abstract class 中 isHandling() 的行為跑。

source code

嗯...好像沒什麼好講的,也就這麼一行大家應該也都看得懂
收工~


上一篇
Laravel:深入Collection
下一篇
Laravel:深入Schedule
系列文
花式PHP31

尚未有邦友留言

立即登入留言