Node-REDのFunctionノードを使ってフローのロギングをしてみた

この記事は[Node-RED Advent Calendar 2019 8日目](https://qiita.com/advent-calendar/2019/node-red)の記事です。

突然ですが僕はFunctionノードが好きです。
中でも、よく使う処理を関数化してグローバルコンテクストに保存して、いろいろなFunctionノードで使うというのが特に気に入っています。
多くの方がすごく嗜好が偏っていると思われたと思いますが、そんなことは気にせずその拡張版としてこんなの作ってみましたというご紹介です。

まずは全体像から、今回作ったフローがコチラ。

![log_flow_sample.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/192402/50ba9198-a695-59f6-ccfd-fbfba4bd3a8c.png)

```json:flows.json
[{"id":"7ba2e31e.491a2c","type":"tab","label":"ログサンプルフロー","disabled":false,"info":""},{"id":"90819ded.082c9","type":"inject","z":"7ba2e31e.491a2c","name":"","topic":"","payload":"","payloadType":"date","repeat":"","crontab":"","once":true,"onceDelay":0.1,"x":160,"y":140,"wires":[["ebadb29e.5b88"]]},{"id":"ebadb29e.5b88","type":"function","z":"7ba2e31e.491a2c","name":"class Log","func":"global.set('Log', class {\n    constructor(level, logFilepath) {\n        this.level = level.toUpperCase();\n        this._logFilepath = logFilepath;\n        this._log = [];\n    }\n    \n    trace(logString) {\n        if ([\n            'DEBUG',\n            'INFO',\n            'WARN',\n            'ERROR',\n            'FATAL',\n        ].includes(this.level)) return;\n        this._put('TRACE', logString);\n    }\n    \n    debug(logString) {\n        if ([\n            'INFO',\n            'WARN',\n            'ERROR',\n            'FATAL',\n        ].includes(this.level)) return;\n        this._put('DEBUG', logString);\n    }\n    \n    info(logString) {\n        if ([\n            'WARN',\n            'ERROR',\n            'FATAL',\n        ].includes(this.level)) return;\n        this._put('INFO', logString);\n    }\n    \n    warn(logString) {\n        if ([\n            'ERROR',\n            'FATAL',\n        ].includes(this.level)) return;\n        this._put('WARN', logString);\n    }\n    \n    error(logString) {\n        if ([\n            'FATAL',\n        ].includes(this.level)) return;\n        this._put('ERROR', logString);\n    }\n    \n    fatal(logString) {\n        this._put('FATAL', logString);\n    }\n    \n    _put(level, logString) {\n        const now = new Date();\n        const yyyy = now.getFullYear();\n        const mm = `0${now.getMonth() + 1}`.slice(-2);\n        const dd = `0${now.getDate()}`.slice(-2);\n        const HH = `0${now.getHours()}`.slice(-2);\n        const MM = `0${now.getMinutes()}`.slice(-2);\n        const SS = `0${now.getSeconds()}`.slice(-2);\n        const timestamp = `${yyyy}-${mm}-${dd} ${HH}:${MM}:${SS}`;\n        this._log.push(`[${timestamp}] ${level.toUpperCase()} - ${logString}`);\n    }\n    \n    output(flowMsg) {\n        flowMsg.payload = this._log.join(\"\\n\");\n        flowMsg.filename = this._logFilepath;\n    }\n});","outputs":0,"noerr":0,"x":360,"y":140,"wires":[]},{"id":"94a5ac10.d26f7","type":"function","z":"7ba2e31e.491a2c","name":"Logクラスインスタンス化","func":"const Log = global.get('Log');\nmsg.logger = new Log(msg.logLevel, msg.logFilepath);\n\nreturn msg;","outputs":1,"noerr":0,"x":410,"y":340,"wires":[["4bf042e3.15de9c"]]},{"id":"76ad6fd1.e77c6","type":"inject","z":"7ba2e31e.491a2c","name":"","topic":"","payload":"","payloadType":"date","repeat":"","crontab":"","once":false,"onceDelay":0.1,"x":160,"y":260,"wires":[["ce17419b.1a4e3"]]},{"id":"ce17419b.1a4e3","type":"change","z":"7ba2e31e.491a2c","name":"Log設定","rules":[{"t":"set","p":"logLevel","pt":"msg","to":"trace","tot":"str"},{"t":"set","p":"logFilepath","pt":"msg","to":"","tot":"str"}],"action":"","property":"","from":"","to":"","reg":false,"x":360,"y":260,"wires":[["94a5ac10.d26f7"]]},{"id":"59c5455d.e2bd7c","type":"debug","z":"7ba2e31e.491a2c","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","targetType":"full","x":510,"y":580,"wires":[]},{"id":"4bf042e3.15de9c","type":"function","z":"7ba2e31e.491a2c","name":"なんかロジック","func":"const logger = msg.logger;\n\nlogger.trace('これはtraceログ');\nlogger.debug('これはdebugログ');\nlogger.info('これはinfoログ');\nlogger.warn('これはwarnログ');\nlogger.error('これはerrorログ');\nlogger.fatal('これはfatalログ');\n\nreturn msg;","outputs":1,"noerr":0,"x":380,"y":420,"wires":[["803e362.85db4c8"]]},{"id":"803e362.85db4c8","type":"function","z":"7ba2e31e.491a2c","name":"ログ出力","func":"msg.logger.output(msg);\n\nreturn msg;","outputs":1,"noerr":0,"x":360,"y":500,"wires":[["93cb97d2.ed7a88"]]},{"id":"93cb97d2.ed7a88","type":"file","z":"7ba2e31e.491a2c","name":"","filename":"","appendNewline":true,"createDir":true,"overwriteFile":"false","encoding":"none","x":350,"y":580,"wires":[["59c5455d.e2bd7c"]]}]
```

## グローバルコンテクストにLogクラスを定義

`class Log`とタイトルがついているFunctionノードのソースはこんな感じです。

```javascript
global.set('Log', class {
    constructor(level, logFilepath) {
        this.level = level.toUpperCase();
        this._logFilepath = logFilepath;
        this._log = [];
    }
    
    trace(logString) {
        if ([
            'DEBUG',
            'INFO',
            'WARN',
            'ERROR',
            'FATAL',
        ].includes(this.level)) return;
        this._put('TRACE', logString);
    }
    
    debug(logString) {
        if ([
            'INFO',
            'WARN',
            'ERROR',
            'FATAL',
        ].includes(this.level)) return;
        this._put('DEBUG', logString);
    }
    
    info(logString) {
        if ([
            'WARN',
            'ERROR',
            'FATAL',
        ].includes(this.level)) return;
        this._put('INFO', logString);
    }
    
    warn(logString) {
        if ([
            'ERROR',
            'FATAL',
        ].includes(this.level)) return;
        this._put('WARN', logString);
    }
    
    error(logString) {
        if ([
            'FATAL',
        ].includes(this.level)) return;
        this._put('ERROR', logString);
    }
    
    fatal(logString) {
        this._put('FATAL', logString);
    }
    
    _put(level, logString) {
        const now = new Date();
        const yyyy = now.getFullYear();
        const mm = `0${now.getMonth() + 1}`.slice(-2);
        const dd = `0${now.getDate()}`.slice(-2);
        const HH = `0${now.getHours()}`.slice(-2);
        const MM = `0${now.getMinutes()}`.slice(-2);
        const SS = `0${now.getSeconds()}`.slice(-2);
        const timestamp = `${yyyy}-${mm}-${dd} ${HH}:${MM}:${SS}`;
        this._log.push(`[${timestamp}] ${level.toUpperCase()} - ${logString}`);
    }
    
    output(flowMsg) {
        flowMsg.payload = this._log.join("\n");
        flowMsg.filename = this._logFilepath;
    }
});
```

コンストラクタの引数でログレベルと出力ファイルパスを指定するようにしています。
ログ出力形式はお好みのフォーマットにアレンジしていただいたりするといいと思います。

## msgにLogクラスをインスタンス化

`Logクラスインスタンス化`とタイトルがついているFunctionノードのソースはこんな感じです。

```javascript
const Log = global.get('Log');
msg.logger = new Log(msg.logLevel, msg.logFilepath);
return msg;
```

Logクラスをインスタンス化してmsgオブジェクトに持たせています。
手前のChangeノードでログレベルとログ出力するファイルパスを設定するようにしてみました。
こんな感じでFunctionノードはできるだけロジックだけにして可変な値を外に出すようにするのが個人的に気に入っています。

## ログる

`なんかロジック`とタイトルがついているFunctionノードのソースはこんな感じです。

```javascript
const logger = msg.logger;

logger.trace('これはtraceログ');
logger.debug('これはdebugログ');
logger.info('これはinfoログ');
logger.warn('これはwarnログ');
logger.error('これはerrorログ');
logger.fatal('これはfatalログ');

return msg;
```

この例では特にロジックはないんですが…。`logger.info`みたいな感じでログを残せます。

## ログをファイル出力

`ログ出力`とタイトルがついているFunctionノードのソースはこんな感じです。

```javascript
msg.logger.output(msg);
return msg;
```

`output`メソッドを引数にmsgオブジェクトを入れて呼ぶと後続のFileノードに渡す変数をmsgオブジェクトに追加してくれるようにしてあります。

注意点としてFileノードの設定について、`動作`は`ファイルへ追記`にしておくと既に出力されているログを上書きして消してしまうことがありません。
また、`メッセージの入力のたびに改行を追加`にチェックを入れるときれいに出力されます。

![filenode_config.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/192402/32a587c3-b52c-b40e-23be-f98ec8c5cb5d.png)

## 出力結果

こんな感じでファイル出力されます。

```
[2019-12-08 10:15:13] INFO - これはinfoログ
[2019-12-08 10:15:13] WARN - これはwarnログ
[2019-12-08 10:15:13] ERROR - これはerrorログ
[2019-12-08 10:15:13] FATAL - これはfatalログ
```

この時はログレベルを`info`で設定していたのでTRACEとDEBUGレベルのログは出力されていません。
このあたりは実際に動かしてご確認いただけるとわかりやすいと思います。

## まとめ

この他にもよく使う機能を関数やクラスにしてグローバルコンテクストから呼び出すのが気に入って使っています。
ちょっとマニアックな内容だったかもしれませんが、ご参考になれば幸いです。