loglevelを使用してクライアントサイドのログを収集する

初めに

昨今、ブラウザはビデオ会議、地図、３Dの描画など多くのことができるようになってきました。
それに伴って、かつてはサーバー側のログを読むだけで可能であった障害対策が難しくなってきました。
本稿では、そのようなケースでクライアントサイドのログを容易に収集するためのライブラリであるloglevelについて記述します。

なお、クライアントサイドのログについての全般的な話はLogging Errors in Client-Side Applicationsの記事が優れています。

loglevel

loglevelはJavaScript用のシンプルなロギングツールです。
https://github.com/pimterry/loglevel

loglevelは以下のような特徴を有しています。

• 特定のレベル(trace/debug/info/warn/error)でコンソールオブジェクトにログを記録します。
• ロギングをレベルによってフィルタリングすることができます。例えば開発環境ではdebugレベルまで出力するが、本番環境ではerrorレベルとするということが可能です。

import log from 'loglevel'
log.setLevel("info")
log.debug('１２３４５')
log.info('アイウエオ')
log.warn('かきくけこ')
log.error('サシスセソ')

さて、ここまでだと、consoleとの違いがあまりありませんが、loglevelはプラグインを作成できます。
プラグインによってログの内容を別のサーバーに通知したり、ローカルストレージに記録することが可能です。

loglevelのログを別サーバーに送信する

loglevelを別サーバーに送信するにはlogleve-plugin-remoteプラグインを使用します。
https://github.com/kutuluk/loglevel-plugin-remote

送信内容をキューに蓄えておき、指定のタイミングでサーバーに送信します。
仮に送信に失敗した場合、送信タイミングを遅らせて再実行します。

以下のサンプルは10秒間隔にログを送信する例です。

 import log from 'loglevel';
 import remote from 'loglevel-plugin-remote';
 remote.apply(log, {
   url: 'http://エンドポイント',
   method: 'POST',
   headers: {
     'x-api-key': 'xxxxxxxx' // 必要に応じてヘッダーにトークンを入れられる
   },
   capacity: 500,       // キューのサイズ default 500
   interval: 10000,   // 送信感覚 default 1000
   format: log => log // JSONオブジェクトとして送信する場合はformatをオブジェクトのままとする
 })

この時、送信されるデータは以下のようになります。

 {
  "logs": [
    {
      "message": "info module-tastic567",
      "level": {
        "label": "info",
        "value": 2
      },
      "logger": "",
      "timestamp": "2021-11-07T03:03:58.397Z",
      "stacktrace": ""
    },
    {
      "message": "warn module-tastic1234",
      "level": {
        "label": "warn",
        "value": 3
      },
      "logger": "",
      "timestamp": "2021-11-07T03:03:58.570Z",
      "stacktrace": "    at Proxy.onTest (webpack-internal:///./node_modules/cache-loader/dist/cjs.js?!./node_modules/babel-loader/lib/index.js!./node_modules/cache-loader/dist/cjs.js?!./node_modules/vue-loader-v16/dist/index.js?!./src/components/HelloWorld.vue?vue&type=script&lang=js:18:55)\n    at Object.onClick._cache.<computed>._cache.<computed> (webpack-internal:///./node_modules/cache-loader/dist/cjs.js?!./node_modules/babel-loader/lib/index.js!./node_modules/vue-loader-v16/dist/templateLoader.js?!./node_modules/cache-loader/dist/cjs.js?!./node_modules/vue-loader-v16/dist/index.js?!./src/components/HelloWorld.vue?vue&type=template&id=469af010&scoped=true:43:49)\n    at callWithErrorHandling (webpack-internal:///./node_modules/@vue/runtime-core/dist/runtime-core.esm-bundler.js:6824:22)\n    and 2 more"
    }
  ]
}

ログの送信先

ログを送信する場合、当然、送信先の開発・運用を行う必要があります。
今回はAWS API Gateway + Lambdaを利用する例を紹介します。

AWS API Gateway + Lambdaを利用する例

AWS API GatwayとAWS Lambdaを使用することで容易にRESTAPIを作成することができます。
例えば以下のようなLambda関数を作成するだけで、logの内容がCloud Watchに出力されます。

exports.handler = async (event) => {
   if (event.logs) {
       for (const log of event.logs) {
           console.log(JSON.stringify(log));
       }
   }
   const response = {
       statusCode: 200
   };
   return response;
};

送信元情報を記録する方法

上記の実装だけだと、ログは記録できるが送信元のIPアドレスなどが記録できず解析が困難になります。
送信元情報をLambda関数内で使用するにはAPIGatewayでマッピングテンプレートを使用します。

API Gatewayで作成したメソッドにて「総合リクエスト」を選択します。

その後、マッピングテンプレートを設定することで、その内容にあわせてLambda関数のeventパラメータのプロパティが拡張されます。

今回は以下のような設定を行います。

{
    "stage" : "$context.stage",
    "source_ip": "$context.identity.sourceIp",
    "user-agent": "$context.identity.userAgent",
    "logs":$input.json('$.logs')
}

これにより、以下のようなプロパティがLambda関数内で利用できます。

名称	説明
event['state']	APIのステージ名
event['source_ip']	送信元IPアドレス
event['user-agent']	送信元のユーザーエージェント
event['logs']	送信データのlogsプロパティ

RDSに記録する方法

かつてはlambda関数内でRDSを使用することは同時接続数の問題でアンチパターンになっていましたが、AWS RDS Proxyを使用することで回避できます。
以下のページを参考にすれば、RDS Proxyの設定は行えることでしょう。

• LambdaでRDS Proxy経由でAurora(MySQL)に接続する（IAM認証）
  
• RDS Proxy+RDS(MySQL)の接続について

では以下のようなテーブルに送信されたログを記録する場合を考えてみます。

CREATE TABLE logs(
    id MEDIUMINT NOT NULL AUTO_INCREMENT,
    accessTime DATETIME,
    stage TEXT,
    ip TEXT,
    userAgent TEXT,
    level TEXT,
    message TEXT,
    stacktrace TEXT,
    PRIMARY KEY(id)
)

このテーブルにログを格納するためのLambda関数は以下の通りになります。

let AWS = require('aws-sdk');
const mysql2 = require('mysql2/promise');
const proxy = 'proxy-mysql.AWSPROXYのエンドポイント.amazonaws.com';
const userName = 'admin';

exports.handler = async (event) => {
    const signer = new AWS.RDS.Signer({
	    region: 'ap-northeast-1',
	    hostname: proxy,
	    port: 3306,
	    username: userName
	});    
    let token = signer.getAuthToken({
	    username: userName
	});
    console.log ("IAM Token obtained\n", token);
    const connectionConfig = {
        host: proxy,
        user: userName,
        database: 'log_test',
        ssl: 'Amazon RDS',
        password: token, // tokenの代わりにuserのパスワードを直接入力してもいける
        authPlugins: { mysql_clear_password: () => () => signer.getAuthToken() }
    };

    let connection = await mysql2.createConnection(connectionConfig);
    if (event.logs) {
        for (const log of event.logs) {
            console.log(JSON.stringify(log));
            await connection.query('INSERT INTO logs SET ?', {
                accessTime: log.timestamp,
                level: log.level.label,
                message: log.message,
                stacktrace: log.stacktrace,
                stage: event.stage,
                ip: event.source_ip,
                userAgent: event['user-agent']
            });
        }
    }
    const response = {
        statusCode: 200
    };
    return response;
};

これはmysql2ライブラリに依存しているので、ローカルでnpm install後、そのディレクトリをzipでまとめてアップロードする必要があります。

別サーバーにログを送信する場合の考慮点

ログを別のサーバーに送るということは、不特定多数のユーザーの操作を監視する場合については便利ですがいくつかの考慮すべき事項があります。
まず、何を送信するかです。開発者ツールに出力するのと同じペースでサーバーにデータを送信するのはネットワークの負荷的にも望ましくはないでしょう。ログ収集のためにサービスが停止したとなっては意味がありません。
またネットワークの負荷だけでなく、送信していいデータかどうかは検討する必要があります。例えばクレジットカードの番号など機密情報をログとして別のサーバーに安易に送信するのはよろしくないでしょう。
そして、いくら再送の仕組みがあったところで、そもそもネットワークが使えなくなった場合にログは送られず消滅します。これを回避するには後述のLocalStorageかIndexedDBに格納する方法が望ましいでしょう。
なお、loglevel-plugin-remoteは素晴らしいプラグインですが完璧ではありません。
GitHubのページにも以下のように開発中である胸が記載されています。

This plugin is under active development and should be considered as an unstable. No guarantees regarding API stability are made. Backward compatibility is guaranteed only by path releases.

必要に応じて自分で修正を行う必要があります。例えば、以下のプルリクエストで言われているflush機能は送信間隔が大きい場合、必要であると考えられます。

https://github.com/kutuluk/loglevel-plugin-remote/pull/36

loglevelのログをローカルストレージに格納する

不特定多数の人間のログを解析するより、ログを確実に記録することを優先する場合、ローカルストレージにログを記録する考えがあります。
ローカルストレージにログを記録しておき、トラブルが発生した場合に、ユーザに依頼してローカルストレージのログを収集するというワークフローが考えられます。
loglevelのローカルストレージに記録するプラグインにloglevel-localStorageが存在します。

https://github.com/gpcboekema/loglevel-localStorage

 import log from 'loglevel';
 import loglevelLocalStorage from 'loglevel-local-storage';
 loglevelLocalStorage(log, {
   level: 'info',
   prefix(logSev, ...args) {
       // Stringify for storage in localStorage
       const newArgs = args.map(arg => ((typeof arg === 'object' && !(arg instanceof Date)) ? JSON.stringify(arg) : arg));
       return `[${new Date().toISOString()}] ${logSev}: ${newArgs.join(' ')}`;
   },
   callOriginal: true,  // consoleにも出力する
   maxLogStackSize: 10, // １０行を上限とする
 });
 log.info('hogehoge')

loglevelLocalStorageの呼び出しオプションでローカルストレージに記録する行の最大数やストレージのキー名を指定できます。

以下の画像は実際のローカルストレージに格納した結果となります。

loglevelのログをIndexedDBに記録する

ローカルストレージは容易に使用できますが、サイズには厳しい上限があります。
もしより多くのログを保持する必要がある場合はIndexedDBを利用します。

https://developer.mozilla.org/ja/docs/Web/API/IndexedDB_API

残念なことにloglevelのIndexedDBのプラグインは存在しないので自作する必要があります。
これはloglevel-localStorageのコードを流用すれば容易に作成できます。

まず、IndexedDBのAPIをそのまま使用するのは辛いのでIndexedDBのライブラリであるidbを利用します。
https://github.com/jakearchibald/idb

idbを導入することでPromiseを利用した実装が可能になります。これを利用してローカルストレージの代わりにIndexedDBに記録するようにした内容が以下の通りです。

loglevelIdb.js

 const idb = require('idb');
 const _ = require('lodash');
 
 /**
  * @description
  * Extend loglevel with new plugin which will send log information to the log-sever
  *
  * @param {object} logger loglevel instance to be extended
  * @param {object} options
  * @param {string} [options.storeKey='loglevelIdb'] Name for the store in localStorage.
  * @param {number} [options.maxLogStackSize=100] Max stack size to store.
  * @param {boolean} [options.callOriginal=false] If set to true - original loglevel method for logging would be called
  * @param {string|number} [options.level=logger.levels.WARN] Log level. Either string or number, {@see logger.setLevel}.
  * @example
  * loglevelLocalStorage(log,{level:'info',prefix: function(logSev,message) {
  *     return '[' + new Date().toISOString() + '] ' + logSev + ': ' + message;
  * }})
  */
 
 var loglevelIdb = async function loglevelIdb(logger, options) {
     if (!logger || !logger.methodFactory) throw new Error('loglevel instance has to be specified in order to be extended');
     const _db = await idb.openDB(options && options.storeKey || 'loglevelIdb', 1, {
       upgrade(db) {
         db.createObjectStore('logs', {
           // The 'id' property of the object will be the key.
           // If you generate a new key 1000 times per second day and night, you won’t run into this limit for over 285000 years.
           // https://stackoverflow.com/questions/18653019/indexeddb-how-to-reseed-reset-auto-increment-key-to-0-or-1
           keyPath: 'id',
           // If it isn't explicitly set, create a value by auto incrementing.
           autoIncrement: true
         });
       }
     });
 
     var _logger = logger,
         _maxLogStackSize = options && options.maxLogStackSize || 100,
         _callOriginal = options && options.callOriginal || false,
         _prefix = options && options.prefix,
         _level = options && options.level || _logger.levels.WARN,
         _originalFactory = _logger.methodFactory,
         _logStack = [];
 
     _logger.methodFactory = function (methodName, logLevel) {
         var rawMethod = _originalFactory(methodName, logLevel);
 
         return function (/* ...message */) {
             var args = Array.prototype.slice.call(arguments, 0);
 
             var message;
             if (typeof _prefix === 'string') {
                 message = _prefix + args.join(' ');
             }
             else if (typeof _prefix === 'function') {
                 message = _prefix.apply(null, Array.prototype.concat.apply([methodName], args));
             }
             else {
                 message = methodName + ': ' + args.join(' ');
             }
 
             if (_callOriginal) {
                 rawMethod.apply(null, arguments);
             }
             // Push to stack
             _logStack = _logStack.slice(-_maxLogStackSize);
             _logStack.push({
               time: new Date().toISOString(),
               loglevel: methodName,
               message: message
             });
 
             //store to localStorage.
             _store();
         };
     };
 
     // Set severity level.
     _logger.setLevel(_level);
 
     var _storeLogStack = async function _storeLogStack() {
         if (!_logStack.length) return;
         try {
           while (_logStack.length > 0) {
             const data = _logStack.shift();
             _db.add('logs', data);
           }
           // Always store a max of {_maxLogStackSize} logs
           let cnt = await _db.count('logs');
           if (cnt > _maxLogStackSize) {
             const deleteKeyList = [];
             let cursor = await _db.transaction('logs').store.openCursor();
             let delCount = cnt - _maxLogStackSize;
             while (cursor) {
               deleteKeyList.push(cursor.key);
               cursor = await cursor.continue();
               --delCount;
               if (delCount === 0) break;
             }
             deleteKeyList.map((k) => _db.delete('logs', k));
           }
         } catch (ex) {
           console.error(ex);
           _logStack = [];
         }
     };
 
     // Creates a debounced function that delays invoking func until after wait milliseconds have elapsed since the last time the debounced function was invoked;
     var _store = _.debounce(_storeLogStack, 250);
 };
 
 module.exports = loglevelIdb;

これはloglevel-localStorageと同様に利用できます。

 import log from 'loglevel';
import loglevelIdb from './loglevelIdb';
loglevelIdb(log, {
  level: 'info',
  callOriginal: true,
  maxLogStackSize: 10,
});

以下の画像が実際のIndexedDBに格納した結果になります。

なお、ログの保有サイズについてはローカルストレージより改善されますが、プライバシーモードなどでブラウザが動く場合や、そもそもブラウザがサポートしていない場合は使用できないので注意してください。

まとめ

クライアントサイドでログを収集するためのloglevelとそのプラグインについて説明しました。
不特定多数のユーザーのログを見る場合はログをサーバーに送信した方がいいでしょう。
ただし、何も考えずに全て送信してはいけませんし、サーバー側の作成、運用コストを考える必要もあります。

確実にログを記録してかつ、無用な運用コストを避けたい場合、ローカルストレージまたはIndexedDBに格納しておく手もあります。
ただし、これらはブラウザの機能なのでサポートされていない場合もありますし、プライバシーモードで起動した場合には使用できない場合があります。

いずれにせよ、loglevelと、そのプラグインを利用あるいは作成することで、自身にあったクライアントサイドのログ収集が可能になります。

参考

• Logging Errors in Client-Side Applications
• API Gateway + Lambda でアクセス元IPアドレスを取得するのに手こずった話
• LambdaでRDS Proxy経由でAurora(MySQL)に接続する（IAM認証）
  
• RDS Proxy+RDS(MySQL)の接続について
• https://github.com/pimterry/loglevel
• https://github.com/kutuluk/loglevel-plugin-remote
• https://github.com/gpcboekema/loglevel-localStorage
• https://github.com/jakearchibald/idb
• https://developer.mozilla.org/ja/docs/Web/API/IndexedDB_API