PHP log 的勝利與挑戰

◎本文翻譯自 The NewYork Times，原作者為 Jonathan Marballi︰
https://open.blogs.nytimes.com/2014/03/25/the-triumphs-and-challenges-of-logging-in-php-and-really-most-languages-probably/

當你的網站出現問題，從 system logs 作為排除故障的起點，是不錯的選擇。伺服器出錯了嗎？檢查 log。網頁看起來不對勁或有亂碼？檢查 log。在重新設計紐約時報網站過程中，我們趁此機會為後端 PHP 框架，開發出輕量級、彈性好用的 log 類別。

我們決定利用開源程式庫，考量過一些選擇後，我們採納了 Symfony 的 Monolog logger。我們也考量過 KLogger 與 Analog 這兩套受歡迎的 log 程式庫，但是發現它們不符合我們的所有需求。KLogger 對輸出到檔案的 log 而言很棒，但缺乏將 log 輸出到其他管道的彈性。Analog 相當輕量而簡單，但是因為採用了靜態架構，難以在我們的單元測試中進行模似 (mock in)。Symfony 的 log 似乎是最輕量、最富彈性與延展性的。

為了建構我們的實作，我們從所需的 log-line 格式開始：

%datetime% %serverName% %uniqueId% %debugLevelName% |[%codeInfo%] %message%

例如：

2014/03/04+17:28:05T-0500 localhost 53165372b15fc DEBUG   |[Foo\Bar::helloWorld:3] Printing greeting to world  #output #salutation

以上大多數從欄位名稱到數值的對應是相當清楚的。%uniqueId% 是一個隨機字串，可以讓我們找出某單一伺服器端程式執行的所有 log 報表。%message% 則包含訊息與所有的 hashtags。多虧了 Monolog，藉由使用 Monolog 的格式器，可以很容易地運用這套格式。Monolog 格式器讓我們可以在鍵/值對被自動對應到 log-line 格式（像是出現在 log-line 格式 %codeInfo% 中的 $record[“codeInfo”]）前，操作記錄的所有欄位。例如：

use \Monolog\Formatter\LineFormatter;
class LoggerLineFormatter extends LineFormatter {
    public function format(array $record) {
        $record['debugLevelName'] = str_pad($record['debugLevelName'], 7 /* 最長層次長度 */, " ");

        $record["codeInfo"] = "";
        if (isset($record["extra"]["class"]) && isset($record["extra"]["function"]) && isset($record["extra"]["line"])) {
            $record["codeInfo"] = $record["extra"]["class"]."::".$record["extra"]["function"].":".$record["extra"]["line"];
        }

        //傳回 parent
        return parent::format($record);
    }
}

一旦 LineFormatter 設定好，我們可以將其連接到 Monolog logger 上，好讓所有被抓取的 log 自動送進去：

//logger 初始化
$this-＞monologLogger = new Monolog\Logger('default');
//取得行格式器
$monologFormat = "%datetime% %serverName% %uniqueId% %customLevelName% |[%codeInfo%] %message%\n";
$dateFormat = "Y/m/d+H:i:s\TO";
$monologLineFormat = LoggerLineFormatter($monologFormat, $dateFormat);
//建立 Stream 處理器（會讓 Monolog 寫到本地 log 檔）
$streamHandler = new Monolog\Handler\StreamHandler('/path/to/log', ERROR);
$streamHandler-＞addFormatter($monologLineFormat);
$this-＞monologLogger-＞pushHandler($streamHandler);

我們實作出將 log 寫到磁碟與用戶端 FireBug 插件的通道。接著我們設定環境，好讓開發伺服器抓取所有層級的 log（從 TRACE 到 ERROR）。在產品環境上，我們只抓取 ERROR。Monolog 提供設定 log 門檻的方法，簡化了這些設定。當我們決定加入 Sentry 通道時，只需要加入幾行程式：

//建立 Raven 處理器（讓 Monolog 自動發送 log 訊息給 Sentry）
$ravenHandler = new Monolog\Handler\RavenHandler(new Raven_Client('https://sentry-url'), DEBUG);
$ravenHandler-＞addFormatter($monologLineFormat);
$this-＞monologLogger-＞pushHandler($ravenHandler);

StreamHandler 與 RavenHandler 兩者都有 log 層級的參數。例如，以下的事件 log 會送到本地 log 檔案與 Sentry：

$this-＞monologLogger-＞addRecord(ERROR, 'This is an error message #yikes');

而，因為除錯層級低於 StreamHandler 最低的 log 層級 ERROR，所以底下的 log 只會被記錄到 Sentry：

$this-＞monologLogger-＞addRecord(DEBUG, 'This is a debug message #info');

我們採用兩種策略讓 log 易於分析。每個進來的要求在 log 中都有唯一的鍵值。因此我們可以輕易地追蹤出單一執行的所有事件。我們使用了 hashtags，以便輕易找出特定類型（例如 #apirequest、#missingdata）的問題。

Hashtags 是分類 log 項目一個快速且有效的方式。透過像是把所有 #apirequest 項目，都轉給負責 API 的團隊之類的做法，我們希望能好好利用這些類別。

我們對 Monolog 與我們的 hashing 解決方案很滿意。在我們的重新設計工作中，它們成為了邁向更棒 NYTimes.com 的有力助手。