Published on

NodeJS 使用 pino 在 AWS Elastic beanstalk 上正確顯示 log

Authors
  • avatar
    Name
    Luke Wu
    Twitter

前言

log (日誌)一直以來都是我們在開發程式時重要的幫手，對於了解程式的運作狀態以及找出錯誤都是非常重要的存在。而反過來說，沒效率的 log 也可能會造成開發人員的困擾與誤解，所以說好的 log 設定也是對開發系統來說很重要的一個課題！

以 node.js 來說，雖然 javascript 本身就有提供如 console.log, console.error 等函數，不過要對應真實系統的需求可能還是稍嫌不足了一點，也因此有許多相關的函式庫應運而生，如winston,bunyan,pino 等。其中，pino 因為有高效的執行速度而知名，也是我在開發 node.js 時最常使用的函式庫。

本文主要探討在 AWS Elastic Beanstalk 上使用 pino 的一些注意事項，包含：

  1. 正確顯示 JSON 格式的 log
  2. 如何將 log 依據層級寫入不同檔案

關於 pino 的基礎教學，可以參考它們的官方網站

正確顯示 JSON 格式的 log

使用 pino 的其中一個特色就是它使用了 JSON 的格式，雖然第一眼看起來比純文字要複雜一點，但好處就是在當你有大量 log 需要處理時，可以快速使用 JSON 資料中的屬性(像是 log 層級、時間戳等)過濾出你想要檢視的 log。

不幸的是，因為 Amazon Linux 2 使用了 rsyslog 作為集中管理 log 的方案，在你的 node.js 應用程式送出 log 之後，rsyslog 還會在每行 log 開頭加入一段包含時間、IP 位址以及應用程式名稱的前綴

從這樣:

{"level":30,"time":1664851979134,"pid":20379,"hostname":"MacBook-Pro-3","msg":"hello world!"}

變成這樣:

Oct 10 17:00:00 ip-10-48-41-129 web: {"level":30,"time":1664851979134,"pid":20379,"hostname":"MacBook-Pro-3","msg":"hello world!"}

而後果就是當 log 實際寫入檔案中儲存時，JSON 的格式就被破壞掉了，基本上也就喪失了原本使用 JSON 格式的意義。

解決方案就是複寫預設的 rsyslog 設定檔。可以在根目錄的 .elasticbeanstalk 資料夾(沒有也可以自己建一個)底下加入一個 .config 設定檔(可任意命名)：

.elasticbeanstalk/log.config

files:
  "/opt/elasticbeanstalk/config/private/rsyslog.conf.template":
    mode: "000644"
    owner: root
    group: root
    content: |
      # This rsyslog file redirects Elastic Beanstalk platform logs.
      # Logs are initially sent to syslog, but we also want to divide
      # stdout and stderr into separate log files.

      template(name="SimpleFormat" type="string" string="%msg%\n")
      $EscapeControlCharactersOnReceive off

      {{range .ProcessNames}}if $programname  == '{{.}}' then {
        *.=warning;*.=err;*.=crit;*.=alert;*.=emerg /var/log/{{.}}.stderr.log; SimpleFormat
        *.=info;*.=notice /var/log/{{.}}.stdout.log; SimpleFormat
      }
      {{end}}

這裡我們用了一個沒有前綴，只有加入換行的 SimpleFormat 模板取代了預設的格式。這樣一來，儲存下來的 log 檔案就會是正統的 JOSN 格式了！

需要注意的是在 Amazon Linux 2 版本 5.1.0 之前跟之後的設定會稍有不同，上面的寫法適用於 5.1.0 之後的版本。更多細節可以參考這份 gist

另外，加入這個設定檔之後，可能還需要重建(rebuild) Elastic Beanstalk 的環境，相關的改動才會生效。如果不想要每次改動設定都要重建環境的話，可以加入一個 post deploy 的 hook，在每次部署之後重啟 rsyslog 的服務。參考這個解答

將 log 依照層級寫入不同檔案

雖然剛剛的設定解決了格式的問題，但在找資料的過程中我一直有個疑惑，就是在設定檔的這幾行：

    *.=warning;*.=err;*.=crit;*.=alert;*.=emerg /var/log/{{.}}.stderr.log; SimpleFormat
    *.=info;*.=notice /var/log/{{.}}.stdout.log; SimpleFormat

這裡的設定應該會將層級在 warning 以上的 log 寫入 stderr.log，並將 warning 以下的 log 寫入 stdlog.log 才對，但在實務上我們會發現所有的 log 都被寫入了 stdlog.log。

後來發現 pino 在不同 log 層級只是會在 JSON 中加入不同的 level 屬性值，但是 syslog 並有沒辦法分辨這個屬性，也因此所有從 node.js 應用程式寫入到 stdout(或 stderr) 的 log 對於 syslog 而言都會是同一個(預設)層級，自然也都會寫入到同一個檔案裡。

如果想讓 pino 的層級能夠反映到 syslog 的層級中，我使用的方法是用pino-systemd-prefix-transport

當然，不用透過 syslog 直接用 node.js 寫入到檔案中可能也是一個相對來說比較簡單的選擇。

Discuss on Twitter • View on GitHub