株式会社日立製作所 中村豊
#はじめに
今回は、Node-REDが出力するログについて、そのカスタマイズの例を紹介します。
#タイムスタンプの形式を変更する
デフォルトの設定で出力したNode-REDのログのタイムスタンプの形式はdd MMM hh:mm:ssです。出力したNode-REDのログを次に示します。
10 Jul 18:49:35 - [info] Node-RED バージョン: v0.20.7
10 Jul 18:49:35 - [info] Node.js バージョン: v10.16.0
10 Jul 18:49:35 - [info] Linux 3.10.0-957.21.3.el7.x86_64 x64 LE
10 Jul 18:49:35 - [info] パレットノードのロード
トラブルシューティングや、性能測定で正確な時刻情報が必要な場合は、タイムスタンプの形式をyyyy-mm-dd hh:mm:ss.sssに変更することができます。タイムスタンプの形式をyyyy-mm-dd hh:mm:ss.sssに変更する手順を次に示します。
##(手順)
###1. 定数宣言の追加
Node-REDの設定ファイル(settings.js)の先頭に、タイムスタンプの形式変更に使用する定数options、dateTimeFormat、levels、levelNamesの宣言を追加します。
// ...省略
// The `https` setting requires the `fs` module. Uncomment the following
// to make it available:
//var fs = require("fs");
// ここからoptions, dateTimeFormat, levels, levelNamesを追加
const options = {
year:'numeric',month:'2-digit',day:'2-digit',hour:'2-digit',
minute:'2-digit',second:'2-digit',hour12:false
};
const dateTimeFormat = Intl.DateTimeFormat('japanese', options);
const levels = {
off:1,fatal:10,error:20,warn:30,info:40,debug:50,trace:60,audit:98,metric:99
};
const levelNames = {
10:"fatal",20:"error",30:"warn",40:"info",50:"debug",60:"trace",98:"audit",
99:"metric"
};
//...省略
###2.handlerプロパティの追加
settings.jsにあるloggingプロパティの末尾にhandlerプロパティを追加します。
＜注意事項＞ handlerプロパティ追加時の注意点
handlerプロパティ追加時は、loggingプロパティの最後にあるauditプロパティの末尾に,を忘れずに追加してください。
//...省略
// Whether or not to include audit events in the log output
audit: true, // comma(,)を忘れずに追加
// ここからhandlerプロパティを追加
handler: function(conf) {
return function(msg) {
var date = new Date(msg.timestamp);
var dateString = dateTimeFormat.format(date) + '.' + ('00' + date.getMilliseconds()).slice(-3);
switch (msg.level) {
case levels.metric:
console.log(dateString+" ["+levelNames[msg.level]+"] "+JSON.stringify(msg));
break;
case levels.audit:
console.log(dateString+" ["+levelNames[msg.level]+"] "+JSON.stringify(msg));
break;
default:
if (msg.msg && msg.msg.stack) {
console.log(dateString+" ["+levelNames[msg.level]+"] "+(msg.type?"["+msg.type+":"+(msg.name||msg.id)+"] ":"")+msg.msg.stack);
} else {
var message = msg.msg;
if (typeof message === 'object' && message !== null && message.toString() === '[object Object]' && message.message) {
message = message.message;
}
console.log(dateString+" ["+levelNames[msg.level]+"] "+(msg.type?"["+msg.type+":"+(msg.name||msg.id)+"] ":"")+message);
}
break;
}
}
}
//...省略
この設定で出力したNode-REDのログを次に示します。
2019-07-10 18:57:26.708 [info] Node-RED バージョン: v0.20.7
2019-07-10 18:57:26.708 [info] Node.js バージョン: v10.16.0
2019-07-10 18:57:26.708 [info] Linux 3.10.0-957.21.3.el7.x86_64 x64 LE
2019-07-10 18:57:26.947 [info] パレットノードのロード
#metricsのログ出力を制御する
settings.jsのmetricsプロパティでtrueを指定すると、フローの実行状況やメモリ使用情報等のログ（以降、metricsログと記載）が出力されます。
metricsログを出力すると、ノードの実行情報などが大量に出力されます。例として、サンプルフローとフローを実行した時のmetricsログを次に示します。
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"aa65c45e.b133b8","event":"node.inject.send","msgid":"86cfed74.6d6bb","timestamp":1563754592508}
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"58462668.a5eeb8","event":"node.file in.receive","msgid":"86cfed74.6d6bb","timestamp":1563754592509}
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"58462668.a5eeb8","event":"node.file in.send","msgid":"86cfed74.6d6bb","timestamp":1563754592512}
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"efd86c96.b933f","event":"node.function.receive","msgid":"86cfed74.6d6bb","timestamp":1563754592512}
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"efd86c96.b933f","event":"node.function.send","msgid":"86cfed74.6d6bb","timestamp":1563754592513}
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"21ed715a.b4f4be","event":"node.file.receive","msgid":"86cfed74.6d6bb","timestamp":1563754592513}
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"efd86c96.b933f","event":"node.function.duration","msgid":"86cfed74.6d6bb","value":2.05,"timestamp":1563754592514}
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"21ed715a.b4f4be","event":"node.file.send","msgid":"86cfed74.6d6bb","timestamp":1563754592515}
22 Jul 09:16:32 - [metric] {"level":99,"nodeid":"97af54b3.9cad78","event":"node.debug.receive","msgid":"86cfed74.6d6bb","timestamp":1563754592515}
22 Jul 09:16:38 - [metric] {"level":99,"event":"runtime.memory.rss","value":132063232,"timestamp":1563754598380}
22 Jul 09:16:38 - [metric] {"level":99,"event":"runtime.memory.heapTotal","value":104415232,"timestamp":1563754598380}
22 Jul 09:16:38 - [metric] {"level":99,"event":"runtime.memory.heapUsed","value":67209096,"timestamp":1563754598380}
metricsログに出力されるeventには実行したノードの情報が含まれています。6行目と8行目のログには、node.file.receive、node.file.sendが出力されていることから、fileノードのログということが分かります。また、10、11、12行目のログはメモリ使用情報のログです。
必要なmetricsログのみ出力するように設定することで、ログの出力量を抑えることができます。必要なmetricsログのみ出力する手順を次に示します。
##(手順)
上述した「タイムスタンプの形式を変更する」の手順に加えて、以下を実施します。
###1. metricsログの出力設定
settings.jsのmetricsプロパティでtrueを指定します。
// Whether or not to include metric events in the log output
metrics: true,
###2. 必要とするノードのevent確認
フローを実行し出力されたmetricsログの中から、必要とするノードのeventを確認します。
###3. ログに出力するeventの設定
settings.jsのhandler内にあるmetricsログ出力箇所を、手順1で確認したeventのみログ出力するように編集します。以下の＜対象event＞のみログ出力する設定を次の図に示します。
＜対象event＞
・ node.file.receive
・ node.file.send
・ runtime.memory.heapUsed
//...省略
switch (msg.level) {
case levels.metric:
// ここから＜対象event＞のみ出力するswitch文を追加
switch (msg.event) {
case 'node.file.receive':
case 'node.file.send':
case 'runtime.memory.heapUsed':
console.log(dateString+" ["+levelNames[msg.level]+"] "+JSON.stringify(msg));
break;
default:
break;
}
break;
//...省略
この設定でサンプルフローを実行すると、metricsログにはeventの値がnode.file.receive、node.file.send、runtime.memory.heapUsedのログのみ出力されます。
2019-07-22 09:38:02.462 [metric] {"level":99,"nodeid":"21ed715a.b4f4be","event":"node.file.receive","msgid":"1daf9d19.086ce3","timestamp":1563755882462}
2019-07-22 09:38:02.464 [metric] {"level":99,"nodeid":"21ed715a.b4f4be","event":"node.file.send","msgid":"1daf9d19.086ce3","timestamp":1563755882464}
2019-07-22 09:38:06.534 [metric] {"level":99,"event":"runtime.memory.heapUsed","value":45531752,"timestamp":1563755886534}
#おわりに
本稿ではNode-REDのログ出力のカスタマイズの例を紹介しました。Node-REDを便利に使うための一例として参考にしていただければと思います。