2020-05-06

【Node.js】log4jsの追記されたログだけを定期的にDiscordに通知する

サーバーがエラーを吐いてないかを定期的に通知するプログラムを作る。

前回の続き

この記事は前回の続きである。

【Node.js】定期的にDiscordに連絡してくるNode.jsサーバー機能

この記事では定期的にNode.jsからDiscordのWebhookを通じてメッセージを送信ところまで解説している。

今回の目標

log4.jsによって記録されているログを拾ってDiscordに送信する
プログラム実行開始から通知タイミングまでの時間内で記録されたログだけに絞って抽出する
今回は「2つ」のデータファイル(Warn, Error)からログを取り出すこととする。

この3点を実装し自前のデータ記録サーバーの状況を定期報告するモジュールの実験とする。

★今回作成した全コードは最下部に貼り付けておく。なにかの参考になれば幸いだ。

log4js

おそらくNode.jsで最もよく使われているログファイル生成用npmパッケージ

詳細は私の次の記事を参照

【Node.js】log4js-nodeでログファイルを記録する【v6.1.2】

今回は出力されるログのフォーマットだけ覚えておけば良い。各自自由にログを作ってみて欲しい。

[2020-05-06T23:22:47.132] [ERROR] e - Errorテストです

[2020-05-06T23:22:53.132] [ERROR] e - Errorテストです

[2020-05-06T23:22:59.133] [ERROR] e - Errorテストです

先頭の[]内がタイムスタンプである。ログ1つごとに改行されている。

完成品の実行結果

Discord側。送信と同時にエラーログを追記しているため一部重複が発生するが実際に起こる可能性は稀。

----- Server Periodic Report -----
[2020-05-06T23:22:41.131] [ERROR] e - Errorテストです
[2020-05-06T23:22:41.133] [WARN] w - Warnテストです
----- Server Periodic Report -----
[2020-05-06T23:22:47.132] [ERROR] e - Errorテストです
[2020-05-06T23:22:41.133] [WARN] w - Warnテストです
[2020-05-06T23:22:47.133] [WARN] w - Warnテストです
----- Server Periodic Report -----
[2020-05-06T23:22:53.132] [ERROR] e - Errorテストです
[2020-05-06T23:22:47.133] [WARN] w - Warnテストです
[2020-05-06T23:22:53.132] [WARN] w - Warnテストです
----- Server Periodic Report -----
[2020-05-06T23:22:59.133] [ERROR] e - Errorテストです
[2020-05-06T23:22:59.134] [WARN] w - Warnテストです

今日覚えたいコード

1行づつデータを読む readline

fsとセットで使う。

import * as fs from 'fs'
import * as readline from 'readline'    

const rs_error = fs.createReadStream('../logs/error.log')
const rl_error = readline.createInterface({ input: rs_error, })

//1行づつ処理(新しい方法) 
for await (const line of rl_error) {
    pushLine({ line, exportLine, nowDate }) //メイン処理
}
//1行づつ処理(古い方法)
// rl_error.on('line', (line) => { }

fs.createReadStream

fsのこのコードは基本的には「バイト単位」で読むコード。これだと1行づつというコードは出来ない。
readline.createInterface

そこでreadlineのcreateinterfaceを利用する。これが1行づつ読むためのモジュール

新しい方法(`for await ... of` 構文)

単純に rl_errorから1行づつ読むのをawaitでブロックしながら行うだけという構文だが、少し見慣れない。

公式のReadlineに解説があるがv11.14.0, v10.17.0以降の比較的あたらしい構文。

MDNに更に詳しく乗っているが私も初めて使った構文だ。

この構文を使う理由

殆どのWEBサイトでは rl.on を使う方式で解説されている。こちらは少々冗長になる上に、今回のケースだとファイルを2つ読み込むために rl.on が2つ必要になる。この方法はpromiseが使えないため2つのファイルの差分を一つのレポートに纏めるのが困難であると予想されたためこちらの実装とした。

一定の時間内のデータのみ出力するロジック

上のコードのpushLine内で行っている。

const interval_minute = 0.1 //分でインターバルを指定
const nowDate = dayjs() //現在の日付
let exportLine = [" ----- Server Periodic Report -----"] //出力する文字列(配列で改行)

const pushLine = ({ line, exportLine, nowDate }) => {
    const lineDate = dayjs(line.substring(1, 24)) //ログ側に記録されている日付
    const diff = nowDate - lineDate //ログされた日時から現在までの差を計算
    const diffMinute = diff / 60000 //差を「分」に変換
    if (diffMinute <= interval_minute) { //指定時間以内のデータだけ出力
        exportLine.push(line)
    }
}

コメントの通りである。

ログファイルの先頭からタイムスタンプを取得
setIntervalに指定されている時間 interval_minute以内のデータに絞る(diffMinuteを計算)
1行づつすべて読み込でifで比較

ライブラリを探せばもっとスマートな方法があるかもしれない。

今回の注意点(`for await ... of`のバグ？)

今回は読み込むファイルが2つ。つまりrsとreadlineが1セットで2セット必要。

rsとreadlineの行を先にconstで定義してからfor await ... ofに入ると処理が停止するバグを発見した。

つまり次のコードは動作しないため注意。

    const rs_error = fs.createReadStream('../logs/error.log')
    const rl_error = readline.createInterface({ input: rs_error, })
    const rs_warn = fs.createReadStream('../logs/warn.log')
    const rl_warn = readline.createInterface({ input: rs_warn, })
    //先に全部定義すると、最初のforで止まってしまう

    for await (const line of rl_error) {
        // Error行
        pushLine({ line, exportLine, nowDate })
    }

    for await (const line of rl_warn) {
        // Warn行
        pushLine({ line, exportLine, nowDate })
    }

宣言を移動し次のコードで動作する。

    const rs_error = fs.createReadStream('../logs/error.log')
    const rl_error = readline.createInterface({ input: rs_error, })
    
    for await (const line of rl_error) {
        // Error行
        pushLine({ line, exportLine, nowDate })
    }

    const rs_warn = fs.createReadStream('../logs/warn.log')
    const rl_warn = readline.createInterface({ input: rs_warn, })
    
    for await (const line of rl_warn) {
        // Warn行
        pushLine({ line, exportLine, nowDate })
    }

この件に関しては詳しくは不明。私の実験の中で発見したバグと回避策。なにか情報が頂けたら幸いだ。

所感

バグのため少し手こずってしまった。

２つのファイルを読み込むというちょっとレアなユースケースではあるがreadlineの使い方とfor await ... ofの使い方については別でも応用が効くので知っておいて損はない。

全コード公開

Loggerは自前でlog4jsを使いやすくしているだけのクラス
dayjsは最近人気の日付系ライブラリ。コードは変わるがDateオブジェクトでもOK。
古いon版の例もコメントで記述

import axios from 'axios'
import dayjs from 'dayjs'
import * as fs from 'fs'
import * as readline from 'readline'
import Logger from '../utils/log4.mjs'

const webhook_url = "https://discordapp.com/api/webhooks/各自違うID"
const interval_minute = 0.1 //分でインターバルを指定

Logger.setDir('../logs/')
console.log("Start")

const secondToMilisecond = 60000 * interval_minute //ミリセカンドを分に変換

//繰り返し処理 ループ部
setInterval(() => {
    Logger.e("Errorテストです") //テスト用独自のコード: "../logs/error.logに1行書き込む
    Logger.w("Warnテストです") //テスト用独自のコード: "../logs/warn.logに1行書き込む
    sendMessage() //メイン処理
}, secondToMilisecond)

//繰り返し処理 メイン
const sendMessage = async () => {

    let exportLine = [" ----- Server Periodic Report -----"] //出力する文字列(配列で改行)
    const nowDate = dayjs() //現在の日付

    //1行づつ処理(古い方法)
    // rl_error.on('line', (line) => { 
    //     const lineDate = dayjs(line.substring(1, 24)) //ログ側に記録されている日付
    //     const nowDate = dayjs() //現在の日付
    //     const diff = nowDate - lineDate //ログされた日時から現在までの差を計算
    //     const diffMinute = diff / 60000 //差を「分」に変換
    //     if (diffMinute <= interval_minute) { //指定時間以内のデータだけ出力
    //         exportLine.push(line)
    //     }
    // })

    const rs_error = fs.createReadStream('../logs/error.log')
    const rl_error = readline.createInterface({ input: rs_error, })
    //1行づつ処理(新しい方法) 
    for await (const line of rl_error) {
        // Error行
        pushLine({ line, exportLine, nowDate })
    }

    // 重要：for awaitはrlを先にすべて定義してしまうと処理が止まってしまう(バグ？)
    // 1つ目のfor await ... of が終わってから次のファイルのreadlineを設定すべし
    const rs_warn = fs.createReadStream('../logs/warn.log')
    const rl_warn = readline.createInterface({ input: rs_warn, })
    for await (const line of rl_warn) {
        // Warn行
        pushLine({ line, exportLine, nowDate })
    }

    //すべてのログを処理し終わると実行される
    //rl_error.on('close', () => { 古い方法
    const exportMessage = {
        content: exportLine.join('\r') //改行コードを入れる
    }
    //Discordに送信
    axios.post(webhook_url, exportMessage).then(() => {
        console.log("Sent a report to the Discord ch.")
    }).catch((e) => {
        console.log(`Error: Sending a report to the Discord ch. ${e}`)
        console.log(exportMessage)
    })
}

const pushLine = ({ line, exportLine, nowDate }) => {
    const lineDate = dayjs(line.substring(1, 24)) //ログ側に記録されている日付
    const diff = nowDate - lineDate //ログされた日時から現在までの差を計算
    const diffMinute = diff / 60000 //差を「分」に変換
    if (diffMinute <= interval_minute) { //指定時間以内のデータだけ出力
        exportLine.push(line)
    }
}