[Next.js] pinoを使用した開発速度を向上させるログ設計
概要
今回は実務でログライブラリとしてpinoの導入行ったので、どのように設計・実装を行なったか記事として残しておこうと思います。
pino以外にもログライブラリとしてはさまざまあったので、開発環境ごとに適した選定が必要だと思いますが、個人的にNext.js公式さんがpinoを推していたので、言われるがまま乗っかるのも良いかなと思います。
フロントエンドの実装でログについての記事があまり見られなかったので、今回のこの記事の実装を参考にしていただけると幸いです。
pinoの基本的な使い方
まず、pinoを使用した基本的なログ出力の方法は、以下のようになります。
import pino from 'pino';
const pinoConfig = {
browser: {
asObject: true, // ブラウザで使用できるような設定
},
};
const logger = pino(pinoConfig);
logger.error('hello world error');
logger.warn('hello world warning');
logger.info('hello world info');
{time: 1688712360094, level: 50, msg: 'hello world error'}
{time: 1688712360095, level: 40, msg: 'hello world warning'}
{time: 1688712360095, level: 30, msg: 'hello world info'}
使用方法は非常にシンプルで、loggerに対してどのレベルのログを出力させたいかを選択し、出力させるログ内容を引数で渡してあげるだけです。また、pinoで定義されているログ以外の内容を出力させたい場合も簡単で、オブジェクトでその内容を教えてあげるだけとなります。（詳しくは公式ドキュメントで確認をお願いします）
logger.error({ hoge: 'hogeだよ', fuga: 'fugaだな' }, 'hello world error');
// 出力されるログ
{time: 1688713029796, level: 50, hoge: 'hogeだよ', fuga: 'fugaだな', msg: 'hello world error'}
こういう風に使っているよ
import pino from 'pino';
const pinoConfig = {
browser: {
asObject: true,
},
};
const logger = pino(pinoConfig);
type Option = {
caller: string;
status: number;
}
export const loggerError = (message: string, option: Option) => {
return logger.error(option, message);
};
export const loggerWarn = (message: string, option: Option) => {
return logger.warn(option, message);
};
export const loggerInfo = (message: string, option: Option) => {
return logger.info(option, message);
};
このようにpino自体をラップした関数を定義し、それを各所で使用する実装を行いました。
そのままpinoを各所で使用しても良かったのですが、出力させる情報に一貫性を持たせかったのと、絶対ほしい情報の出力が漏れることが怖かったので、今回はこのような実装にしました。
今回は説明とコードが煩雑になるため記載しなかったですが、実際実務で使用しているものには、ログが出力されているデバイス情報（Mac, iPhone, Android）、ブラウザ情報（chrome, safari）も出力させる情報に含めています。
loggerError('エラーだよ！', { caller: 'ここでエラーが起こっているよ！', status: 400 });
// 出力されるログ
{time: 1688714657886, level: 50, caller: 'ここでエラーが起こっているよ！', status: 400, msg: "エラーだよ！"}
少しログを見やすくしよう
const pinoConfig = {
formatters: {
level: (label: string) => {
return {
level: label,
};
},
},
timestamp: pino.stdTimeFunctions.isoTime,
browser: {
asObject: true,
},
};
const logger = pino(pinoConfig);
loggerError('エラーだよ！', { caller: 'ここでエラーが起こっているよ！', status: 400 });
// 出力されるログ
{time: '2023-07-07T07:25:09.601Z', level: 50, caller: 'ここでエラーが起こっているよ！', status: 400, msg: "エラーだよ！"}
pinoの設定ファイルを少し修正し、出力させるログの表示形式を修正しました。本来なら、levelの値がerrorという文字列に変わってくれるはずなのですが、ブラウザのログだと変わりませんでした（公式）。サーバー側のレンダリングで出力されたログの表示は変わってくれていたので、ブラウザは未対応ということなのかな、と勝手に思っておきます（あんまり深追いしたくない）。
また、サーバー側に出力されるログには、自動的にpidとhostnameの値が付与されます。今回は行わなかったですが、それらの値の制御も行えるようなので、気になった方は確認してみるのも良さそうですね（公式）。
最後に
// 最後に全容を載せておきます
import pino from 'pino';
type Option = {
caller: string;
status: number;
}
const pinoConfig = {
formatters: {
level: (label: string) => {
return {
level: label,
};
},
},
timestamp: pino.stdTimeFunctions.isoTime,
browser: {
asObject: true,
},
};
const logger = pino(pinoConfig);
export const loggerError = (message: string, option: Option) => {
return logger.error(option, message);
};
export const loggerWarn = (message: string, option: Option) => {
return logger.warn(option, message);
};
export const loggerInfo = (message: string, option: Option) => {
return logger.info(option , message);
};
export const loggerDebug = (message: string, option: Option) => {
return logger.debug(option, message);
};
今回はあまり詳しく記載しませんでしたが、実装したログの出力はブラウザ側とサーバー側両方に仕込んでいるため、問題が起こった際は各所で必要なログを出力してくれるように実装しました。そのため、もしバグなどでログが出力された際でも、迅速に原因箇所の特定ができます。
フロントエンドでログ出力と言われてもあまり印象にないかなと思います（僕も無知でした）。ですが、今回の実装でこれだけ仕込んでおけばバグなどが起こってもすぐに対応できそう！という安心感が増した気がしているので、pinoを導入して良かったなぁと思います。
余談
タイトルに「開発速度を向上させる」という少し大きい言葉を使用しましたが、まだpinoを導入して間もないため、「バグの早期発見！」「デバッグしやすい！」のようなことがあったかというとそんなことはありません。今後使用していく上で、導入したけどあんまり意味なかったなぁ…となれば、それもまた記事にできればと思います。
Discussion