Ajari Anda langkah demi langkah cara mencetak log tautan lengkap dengan elegan di node.js

Saat pengguna melaporkan masalah: Saat terjadi kesalahan saat menggunakan fungsi online tertentu, bagaimana cara menemukannya dengan cepat dan akurat? Bagaimana cara melacak pengoptimalan secara efektif ketika antarmuka permintaan tertentu mengembalikan data dengan lambat?

1. Prinsip dan praktik

Seperti yang kita semua tahu, ketika permintaan datang, log berikut mungkin akan dihasilkan:

1. AceesLog: log akses pengguna

2. Pengecualian: log pengecualian kode

3. SQL: log kueri sql

4. Pihak Ketiga: ketiga-

layanan pihak

Bagaimana cara melacak semua log yang dihasilkan oleh permintaan?

Pendekatan umumnya adalah dengan menggunakan requestId sebagai pengidentifikasi unik,

dan kemudian menulis middleware untuk memasukkan requestId ke dalam konteks. Saat pencatatan perlu dilakukan, keluarkan dari konteks untuk dicetak

di layanan pihak ketiga dan log SQL , Anda juga perlu memasukkan requestId ke dalam konteks. RequestId diteruskan ke fungsi yang sesuai untuk dicetak. Terlalu merepotkan untuk meneruskannya lapis demi lapis, dan kodenya juga relatif mengganggu.

Tujuan kami adalah mengurangi gangguan kode, memasukkannya sekali, dan melacaknya secara otomatis.

Setelah diteliti, async_hooks dapat melacak siklus hidup perilaku asinkron. Di setiap sumber daya asinkron (setiap permintaan adalah sumber daya asinkron), ia memiliki 2 ID,

yaitu asyncId (ID siklus hidup sumber daya asinkron saat ini), trigerAsyncId (sumber daya asinkron induk). PENGENAL).

async_hooks menyediakan kait siklus hidup berikut untuk mendengarkan sumber daya asinkron:

asyncHook = async_hook.createHook({
  //Dengarkan pembuatan sumber daya asinkron init(asyncId,type,triggerAsyncId,resource){},
  // Sebelum fungsi callback sumber daya asinkron mulai dijalankan sebelumnya(asyncId){},
  //Setelah fungsi callback sumber daya asinkron mulai dijalankan, setelah(asyncId){},
  // Pantau penghancuran sumber daya asinkron yang dimusnahkan (asyncId) {}
})

Kemudian jika kita membuat pemetaan, setiap asyncId dipetakan ke suatu penyimpanan, dan requestId yang sesuai disimpan di penyimpanan, maka requestId dapat diperoleh dengan mudah.

Kebetulan perpustakaan yang terhubung dengan cls telah dienkapsulasi berdasarkan async_hooks, memelihara salinan data dalam sumber daya asinkron yang sama dan menyimpannya dalam bentuk pasangan nilai kunci. (Catatan: async_hooked perlu digunakan di versi node yang lebih tinggi>=8.2.1) Tentu saja, ada implementasi lain di komunitas, seperti cls-session, node-continuation-local-storage, dll.

Mari kita bahas contoh penggunaan cls-hooked di proyek saya:

/session.js Buat ruang penyimpanan bernama

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

/logger.js cetak log

const sesi = require('./session') 
modul.ekspor = { 
info: (pesan) => 
{ 
const requestId = sesi.get('requestId')
console.log(`requestId:${requestId}`, pesan) 
}, 
kesalahan: (pesan) => 
{ 
const requestId = sesi.get('requestId') 
console.error(`requestId:${requestId}`, pesan) 
} 
}

/sequelize.js sql memanggil logger untuk mencetak log

const logger = require("./logger") 
sekuel baru( 
pencatatan: fungsi (sql, waktu biaya) { 
logger.error( `sql exe : ${sql} | waktu biaya ${costtime} ms` ); 
} )

/app.js Setel requestId, setel requestId untuk mengembalikan header respons, dan cetak log akses

const session = require('./session') 
const logger = memerlukan('./logger') 
fungsi async accessHandler(ctx, selanjutnya) 
{ 
const requestId = ctx.header['x-permintaan-id'] ||.
const params = ctx.request.body ? JSON.stringify(ctx.request.body) : JSON.stringify(ctx.request.query)
//Setel requestId session.run(() => { session.set('requestId', requestId)
logger.info(`url:${ctx.request.path}; params:${params}`) selanjutnya()
//Setel header respons pengembalian ctx.res.setHeader('X-Request-Id',requestId)
}) }

Mari kita lihat log ketika jalur permintaan adalah /home?a=1:

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

Log sql:
requestId:79f422a6-6151-4bfd-93ca-3c6f892fb9ac sql exe:
Dieksekusi (default): SELECT `id` FROM t_user

Anda dapat melihat bahwa log requestId dari seluruh tautan untuk permintaan yang sama adalah sama. Jika nanti ada alarm yang dikirim ke platform alarm, maka kita dapat menemukan seluruh tautan yang dieksekusi oleh permintaan ini berdasarkan requestId.

Siswa yang berhati-hati mungkin memperhatikan bahwa saya juga mengatur requestId di header respons yang dikembalikan oleh antarmuka. Tujuannya adalah jika permintaan ditemukan merespons dengan lambat atau bermasalah, requestId dapat diketahui langsung dari browser dan dianalisis.

2. Overhead kinerja:

Saya melakukan stress test secara lokal.

Ini adalah perbandingan penggunaan memori:

Sekitar 10% lebih banyak daripada tidak menggunakan async_hook.

Tidak apa-apa untuk sistem QPS kami dengan sistem 100 level, tetapi jika ini adalah layanan yang sangat bersamaan, kami mungkin perlu mempertimbangkannya dengan hati-hati.

ps: Jika ada kesalahan mohon tunjukkan jika tidak suka jangan berkomentar.