超今さらExpress触ってみた - その4 やっとテスト書けるよ - の続き。
背景
超今さらExpress触ってみた - その1 Expressって生々しすぎない？ - で express の middleware として morgan という logger を導入したけど、これは HTTP request に応じて自動で吐くやつ。
expressjs/morgan: HTTP request logger middleware for node.js
今回は手動の方の話。
winstonにしてみる
今回の Express アプリの目的はあくまで Cloud Functions なので、log は Stackdriver Logging に送られることになる。
Stackdriver - ハイブリッド モニタリング | Stackdriver | Google Cloud
Stackdriver Logging に Node.js からログを送るライブラリとしてオフィシャルに紹介されているのは
Bunyan または Winston プラグインを使用するか、Node.js 用 Stackdriver Logging クラウド クライアント ライブラリを直接使用して、Node.js アプリケーションから Stackdriver Logging にログを書き込むことができます。
https://cloud.google.com/logging/docs/setup/nodejs
にあるように、
- trentm/node-bunyan: a simple and fast JSON logging module for node.js services
- winstonjs/winston: A logger for just about everything.
の二つ。
シンプルなのは bunyan の方だと思うのだが、winston は transport レイヤーをカスタムすることができ、logger から例えば Webhook や Mail で送信するといったことを手軽に実現できる機能がある。
今回はこれを期待して winston を採用してみようと思う。
組み合わせて試したのは以下のバージョン。
- winston 3.1
- logging-winston 0.9
実は、上の組み合わせは
undefined is a legacy winston transport. ...
と ERROR が起きてしまう。ただし、実際には動作する。という状態なので、安心したい場合は winston@2 系列と組み合わせるのがよいと思う。
最近のアップデートで 0.10.x 系で winston 3 対応している様子は分かるんだけど、中の依存で Node 6 がたぶん意図せず弾かれたり、ややこしい感じなので慌てない方がよさそう。
winstonを入れてみる
というわけで改めて必要なのはこれ。
winstonjs/winston: A logger for just about everything.
winston で logger を作る際の超基本的な構造はこんな感じになります。
logger.js
const winston = require('winston')
const logger = winston.createLogger({
level,
format,
transports
})
module.exports = logger
もうちょっと具体的に書くと、以下のようにしておけばとりあえず動く。
const winston = require('winston')
const logger = winston.createLogger({
level: 'info',
format: new winston.format.simple(),
transports: [new winston.transports.Console()]
})
module.exports = logger
で、index.js（function 側）では
const logger = require('./logger')
module.exports.test = (req, res) => {
logger.info('ok')
res.send('200 ok')
}
のように logger を呼び出して叩く。これで少なくとも functions-emulator では問題なく console に出力される。
この logger は morgan のような express middleware ではないので、function のコードで require していきなり使えます。
Cloud Functions用にlogging-winstonを追加
Google Cloud Functions からは console が STDOUT だから自動的にログが Stackdriver Logging に流れてくれる、ようなことはない1。そこで winston に Stackdriver Logging 用の transport を追加する。
const winton = require('winston')
const {LoggingWinston} = require('@google-cloud/logging-winston')
..
snip)
..
const transports = [
new winston.transports.Console(),
new LoggingWinston()
]
..
snip)
..
const logger = winston.createLogger({
level: 'info',
format: winston.format.simple(),
transports
})
module.exports = logger
てな感じ。
IAM Roleを足す
念のため、メモ。実際に Stackdriver Logging へログを送るには以下の permission ( Role )
logging.logEntries.create ( Logs Writer )
が要ります。ただ、Function に限って言えば Function の実行権限を持っていれば Logging への write 権限も普通はあると思います。
何が嬉しいのか
これで何が嬉しいかというと、とりあえず log level の記述が Stackdriver Logging の期待するものとだいたい一致するところ。
- https://github.com/winstonjs/winston#logging-levels
- https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#logseverity
なんでここが気になるかというと、
ログを書き込む
Cloud Function からログラインを得るには、console.log か console.error を使います。
snip)
- console.log() コマンドには INFO ログレベルがあります。
- console.error() コマンドには ERROR ログレベルがあります。
- 内部システム メッセージには DEBUG ログレベルがあります。
https://cloud.google.com/functions/docs/monitoring/logging
あれー、Warning とかどうすんだー？ というのが気になったから。
もう一つ大事なのは format. 例えば timestamp を自動で入れることもできるし、すべての backtrace を入れた JSON ログ2を作ることもできる。そのうえで Stackdriver Monitoring と組み合わせると、ログ → 監視 → 通知 → 対応（修正）をスムーズに行うことができるようになる。はず。
そのうち
Cloud Functions の外からでもこの組み合わせだけであれこれ ( Project ID とか ) 設定すればイケるんじゃないかと思っているので、今度試す。