ノードでフルリンクのログをエレガントに出力する方法を段階的に説明します

ユーザーが問題を報告した場合: 特定のオンライン機能の使用中にエラーが発生した場合、どのようにすれば迅速かつ正確にエラーを特定できるでしょうか?特定のリクエスト インターフェイスがデータを返すのが遅い場合に最適化を効果的に追跡するにはどうすればよいでしょうか?

1. 原則と実践

ご存知のとおり、リクエストが来ると、おそらく次のログが生成されます。

1. AceesLog: ユーザー アクセス ログ

2. 例外: コード例外ログ

3. SQL: SQL クエリ ログ

4. ThirdParty: サードパーティパーティ サービス

ログ リクエストによって生成されたすべてのログを追跡するにはどうすればよいですか?

一般的なアプローチは、requestId を一意の識別子として使用し、

を

作成する必要がある場合に、その requestId をコンテキストから取り出して印刷することです。

requestId をコンテキストに挿入する必要もあります。この requestId を、レイヤーごとに渡すのは面倒で、コードも比較的面倒です。

私たちの目標は、コードの侵入性を軽減し、一度挿入すれば自動的に追跡できるようにすることです。

研究の結果、async_hooks は各非同期リソース (各リクエストは非同期リソース) で、2 つの ID、

つまり asyncId (非同期リソースの現在のライフサイクル ID)、trigerAsyncId (親非同期リソース)

ID）。

async_hooks は、非同期リソースをリッスンするための次のライフサイクル フックを提供します。

asyncHook = async_hook.createHook({
  //非同期リソースの作成をリッスンします init(asyncId,type,triggerAsyncId,resource){},
  // 非同期リソース コールバック関数の実行が開始される前 before(asyncId){},
  // 非同期リソース コールバック関数の実行開始後、after(asyncId){},
  // 非同期リソースの破棄を監視する destroy(asyncId){}

、

各 asyncId をストレージにマッピングし、対応する requestId をストレージに保存するマッピングを作成すると、requestId を簡単に取得できます。

偶然ですが、cls フックされたライブラリは async_hooks に基づいてカプセル化されており、同じ非同期リソース内にデータのコピーを維持し、キーと値のペアの形式で保存しています。 (注: async_hooked は、node>=8.2.1 以降のバージョンで使用する必要があります。) もちろん、コミュニティには、cls-session、node-continuation-local-storage などの他の実装もあります。

私のプロジェクトで cls-hooked を使用する例について話しましょう。

/session.js 名前付きストレージ スペースを作成します

。 const createNamespace = require('cls-hooked').createNamespace 
const session = createNamespace('requestId-store') 
module.exports = session

/logger.js ログ出力

const session = require('./session') 
module.exports = { 
情報: (メッセージ) => 
{ 
const requestId = session.get('requestId')
console.log(`requestId:${requestId}`, メッセージ) 
}、 
エラー: (メッセージ) => 
{ 
const requestId = session.get('requestId') 
console.error(`requestId:${requestId}`, メッセージ) 
} 
/sequelize.js

SQL は logger を呼び出してログを出力します

const logger = require("./logger") 
newSequelize( 
ロギング：関数（SQL、コストタイム）{ 
logger.error( `sql exe : ${sql} | コストタイム ${コストタイム} ミリ秒` ); 
/app.js

requestId を設定し、応答ヘッダーを返すように requestId を設定し、アクセス ログを出力します

const session = require('./session') 
const logger = require('./logger') 
非同期関数 accessHandler(ctx, next) 
{ 
const requestId = ctx.header['x-request-id'] uuid()
const params = ctx.request.body ? JSON.stringify(ctx.request.body) : JSON.stringify(ctx.request.query)
// requestId を設定 session.run(() => { session.set('requestId', requestId)
logger.info(`url:${ctx.request.path}; params:${params}`) next()
// 応答ヘッダーを設定します ctx.res.setHeader('X-Request-Id',requestId)

リクエストパスが/home?a=1の場合のログを見てみましょう:

アクセス

ログ:
requestId:79f422a6-6151-4bfd-93ca-3c6f892fb9ac url:/home;params:{"a":"1"}

SQLログ:
requestId:79f422a6-6151-4bfd-93ca-3c6f892fb9ac SQL exe:
実行 (デフォルト): SELECT `id` FROM t_user

同じリクエストに対するリンク全体のログ requestId が同じであることがわかります。後でアラーム プラットフォームに送信されたアラームがある場合は、requestId に基づいて、このリクエストによって実行されたリンク全体を見つけることができます。

注意深い学生は、インターフェースから返される応答ヘッダーにも requestId を設定していることに気づくかもしれません。その目的は、リクエストの応答が遅い場合や問題がある場合に、requestId をブラウザから直接取得して分析できるようにすることです。

2. パフォーマンスのオーバーヘッド:

ストレス テストをローカルで実行しました。

これはメモリ使用量の比較です。

async_hook を使用しない場合よりも約 10% 増加します。

100 レベル システムの QPS システムには問題ありませんが、同時実行性の高いサービスの場合は慎重に検討する必要があるかもしれません。

ps: 間違いがあれば指摘してください。気に入らない場合はコメントしないでください。