1. yutakanakamura2

    Posted

    yutakanakamura2
Changes in title
+Node-REDのログ出力をカスタマイズする
Changes in tags
Changes in body
Source | HTML | Preview
@@ -0,0 +1,169 @@
+株式会社日立製作所 中村豊
+
+#はじめに
+ 今回は、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`の宣言を追加します。
+
+```js:settings.js
+// ...省略
+// 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プロパティの末尾に`,`を忘れずに追加してください。
+
+```js:settings.js
+//...省略
+ // 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ログを次に示します。
+![図1.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/545364/0f78dbf6-2b23-7049-456b-2e3d51d1a4b1.png)
+
+```
+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を指定します。
+
+```js:settings.js
+ // Whether or not to include metric events in the log output
+ metrics: true,
+```
+
+###2. 必要とするノードの`event`確認
+ フローを実行し出力されたmetricsログの中から、必要とするノードの`event`を確認します。
+
+###3. metricsログの出力設定
+ settings.jsの`handler`内にあるmetricsログ出力箇所を、手順1で確認した`event`のみログ出力するように編集します。以下の<対象event>のみログ出力する設定を次の図に示します。
+<対象event>
+・ node.file.receive
+・ node.file.send
+・ runtime.memory.heapUsed
+
+```js:settings.js
+//...省略
+ 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を便利に使うための一例として参考にしていただければと思います。
+
+