Tracing id request trong ứng dụng NodeJS

7 min


1043
1.4k shares, 1043 points

Lời giới thiệu

Nếu bạn đã từng viết back-end các ứng dụng NodeJS. Thì việc theo dõi request HTTP thông qua các log là một vấn đề. Thông thường, log của bạn trông giống như sau:

[07/Nov/2018:15:48:11 +0000] User sign-up: starting request validation
[07/Nov/2018:15:48:11 +0000] User sign-up: starting request validation
[07/Nov/2018:15:48:12 +0000] User sign-up: request validation success
[07/Nov/2018:15:48:13 +0000] User sign-up: request validation failed. Reason:
...

Ở đây, các log được trộn lẫn và không xác định chúng thuộc về cùng một request. Mặc dù bạn có thể muốn thấy một cái gì đó như thế này:

[07/Nov/2018:15:48:11 +0000] [request-id:550e8400-e29b-41d4-a716-446655440000] User sign-up: starting request validation
[07/Nov/2018:15:48:11 +0000] [request-id:340b4357-c11d-31d4-b439-329584783999] User sign-up: starting request validation
[07/Nov/2018:15:48:12 +0000] [request-id:550e8400-e29b-41d4-a716-446655440000] User sign-up: request validation success
[07/Nov/2018:15:48:13 +0000] [request-id:340b4357-c11d-31d4-b439-329584783999] User sign-up: request validation failed. Reason:
...

Tham khảo thêm về việc ghi log error tại đây : Bí quyết xử lý và cải thiện về error trên NodeJS

Lưu ý

Phần [request-id: *] có chứa các định danh request tại đây. Các số nhận dạng này sẽ cho phép bạn lọc các log thuộc cùng một request. Hơn nữa, nếu ứng dụng của bạn bao gồm các microservices giao tiếp với nhau qua HTTP. Token nhận dạng request có thể được gửi trong header HTTP. Và được sử dụng để theo dõi chuỗi request trên log được tạo bởi tất cả các microservices trên chuỗi. Rất khó để đánh giá giá trị của tính năng này đối với mục đích chẩn đoán và giám sát.

Là developer, bạn muốn cấu hình framework web hoặc thư viện trình ghi log ở một nơi duy nhất. Và nhận id request được tạo sau đó in vào log tự động. Nhưng thật không may, nó có thể là một vấn đề trong thế giới NodeJS

Trong bài viết này, chúng ta sẽ thảo luận về vấn đề và một trong những giải pháp khả thi.

OK, nhưng nó có phải là vấn đề không?

Trong nhiều ngôn ngữ và nền tảng khác, như vùng chứa JVM và Java Servlet. Nơi các máy chủ HTTP được xây dựng dựa trên kiến ​​trúc đa luồng và blocking I / O.. Nếu đặt một số nhận dạng của chuỗi xử lý request HTTP vào log. Nó đã có thể đóng vai trò là tham số bộ lọc tự nhiên để tracing request cụ thể.

Giải pháp này còn lâu mới là lý tưởng, nhưng nó có thể được nâng cao hơn nữa khi sử dụng Thread-local storage (TLS). TLS về cơ bản là một cách để lưu trữ và truy xuất các cặp key-value trong ngữ cảnh được liên kết với thread hiện tại.

Nhiều thư viện ghi log có các tính năng được xây dựng xung quanh TLS. Ví dụ, hãy xem tài liệu về SLF4J’s Mapped Diagnostic Context.

Do bản chất không đồng bộ của NodeJS, dựa trên event loop, đơn giản là không có gì giống như bộ lưu trữ cục bộ luồng, vì mã JS của bạn đang được xử lý trên một luồng duy nhất. Nếu không có API này hoặc API tương tự, bạn sẽ phải kéo một đối tượng context, chứa id request, tất cả các lệnh gọi xử lý request của bạn.

Ví dụ:

'use strict'
// a primitive logger object
const logger = {
  info: console.log
}
const express = require('express')
const uuidv4 = require('uuid/v4')
const app = express()
app.get('/', function (req, res) {
  req._id = uuidv4(); // generate and store a request id
  logger.info(`Started request handling, request id: ${req._id}`)
  // pass `req` object into the nested call
  fakeDbAccess(req)
    .then((result) => res.json(result))
})
async function fakeDbAccess (req) {
  return new Promise((resolve) => {
    setTimeout(() => {
      logger.info(`Logs from fakeDbAccess, request id: ${req._id}`)
      resolve({ message: 'Hello world' })
    }, 0)
  })
}
app.listen(3000, (err) => {
  if (err) {
    logger.err('The app could not start')
  }
  logger.info('The app is listening on 3000')
})

Trong ứng dụng tưởng tượng này, chúng ta phải chuyển object req vào hàm fakeDbAccess để có thể xuất id request vào log. Hãy nghĩ xem cách tiếp cận này sẽ dư thừa và dễ xảy ra lỗi như thế nào trong các ứng dụng có nhiều route và mô-đun.

May mắn thay, những người từ cộng đồng NodeJS đã nghĩ đến các lựa chọn thay thế cho TLS từ lâu. Và phổ biến nhất trong số các lựa chọn thay thế đó được gọi là Continuation-local storage (CLS).

CLS để giải cứu!

Việc triển khai đầu tiên của CLS là thư viện continuation-local-storage. Nó có định nghĩa sau về CLS:

Continuation-local storage hoạt động giống như lưu trữ cục bộ theo luồng trong lập trình theo luồng, nhưng dựa trên chuỗi callback kiểu NodeJS thay vì luồng..

Nếu bạn kiểm tra API của thư viện, bạn có thể thấy nó phức tạp hơn một chút so với TLS của Java. Nhưng về cốt lõi, nó hoàn toàn giống nhau. Nó cho phép bạn liên kết một object context với một chuỗi lệnh gọi và lấy nó sau.

Thư viện ban đầu dựa trên việc sử dụng API process.addAsyncListener, có sẵn cho đến NodeJS v0.12 và polyfill của nó cho NodeJS v0.12 +. Polyfill thực hiện rất nhiều bản vá nhằm mục đích gói các API NodeJS được tích hợp sẵn. Đó là lý do chính tại sao bạn không nên cân nhắc sử dụng thư viện gốc với các phiên bản hiện đại của NodeJS.

May mắn thay, có một phiên bản tiếp theo của thư viện CLS, được gọi là cls-hooked. Trong NodeJS> = 8.2.1, nó đang sử dụng async_hooks, một API tích hợp của NodeJS . Và mặc dù API vẫn đang thử nghiệm, tùy chọn này tốt hơn nhiều so với tùy chọn có polyfill.

Bây giờ, khi chúng ta có tool phù hợp, chúng ta biết cách tiếp cận vấn đề ban đầu của mình, đó là tracing id request trong log ứng dụng.

Làm thế nào về các giải pháp Out-of-the-box cho Express / Koa / framework khác?

Nếu muốn có id request trong NodeJS, sử dụng cls-hooked và tích hợp nó với framework đang sử dụng. Nhưng có lẽ bạn sẽ muốn sử dụng một thư viện sẽ làm công việc này.

Gần đây, tôi đã tìm kiếm thư viện như vậy và không tìm thấy kết quả phù hợp. Có, có một số thư viện tích hợp các framework web, ví dụ: Express, với CLS. Mặt khác, có những thư viện cung cấp middlewares tạo id request. Nhưng tôi không tìm thấy thư viện kết hợp cả CLS và id request để giải quyết vấn đề tracing id request.

Vì vậy, hãy làm quen với cls-rtracer, một thư viện nhỏ giải quyết một vấn đề không hề nhỏ. Nó cung cấp middleware cho Express và Koa để triển khai tạo id request dựa trên CLS. Và cho phép lấy id request ở bất kỳ đâu trên chuỗi call của bạn.

Việc tích hợp với cls-rtracer về cơ bản yêu cầu hai bước. Cái đầu tiên – gắn middleware vào nơi thích hợp. Thứ hai – cấu hình thư viện ghi log của bạn.

Đây là ví dụ:

'use strict'
const rTracer = require('cls-rtracer')
// that how you can configure winston logger
const { createLogger, format, transports } = require('winston')
const { combine, timestamp, printf } = format
// a custom format that outputs request id
const rTracerFormat = printf((info) => {
  const rid = rTracer.id()
  return rid
    ? `${info.timestamp} [request-id:${rid}]: ${info.message}`
    : `${info.timestamp}: ${info.message}`
})
const logger = createLogger({
  format: combine(
    timestamp(),
    rTracerFormat
  ),
  transports: [new transports.Console()]
})
// now let's configure and start the Express app
const express = require('express')
const app = express()
app.use(rTracer.expressMiddleware())
app.get('/', function (req, res) {
  logger.info('Starting request handling')
  fakeDbAccess()
    .then((result) => res.json(result))
})
async function fakeDbAccess () {
  return new Promise((resolve) => {
    setTimeout(() => {
      logger.info('Logs from fakeDbAccess')
      resolve({ message: 'Hello from cls-rtracer Express example' })
    }, 0)
  })
}
app.listen(3000, (err) => {
  if (err) {
    logger.err('The app could not start')
  }
  logger.info('The app is listening on 3000')
})

Khi được chạy, ứng dụng này tạo ra output tương tự như sau:

2018-12-06T10:49:41.564Z: The app is listening on 3000
2018-12-06T10:49:49.018Z [request-id:f2fe1a9e-f107-4271-9e7a-e163f87cb2a5]: Starting request handling
2018-12-06T10:49:49.020Z [request-id:f2fe1a9e-f107-4271-9e7a-e163f87cb2a5]: Logs from fakeDbAccess
2018-12-06T10:49:53.773Z [request-id:cd3a33a9-32cb-453b-a0f0-e36c65ff411e]: Starting request handling
2018-12-06T10:49:53.774Z [request-id:cd3a33a9-32cb-453b-a0f0-e36c65ff411e]: Logs from fakeDbAccess
2018-12-06T10:49:54.908Z [request-id:8b352536-d714-4838-a372-a8e2cfcb4f53]: Starting request handling
2018-12-06T10:49:54.910Z [request-id:8b352536-d714-4838-a372-a8e2cfcb4f53]: Logs from fakeDbAccess

Lưu ý rằng bản thân việc tích hợp bao gồm việc đính kèm middleware Express được tạo bởi lệnh gọi hàm rTracer.expressMiddleware () và lấy id request với lệnh call rTracer.id (). Vì vậy, nó càng đơn giản càng tốt. Bạn cũng có thể tìm thấy một ví dụ cho các ứng dụng Koa tại đây.

Hy vọng rằng cls-rtracer sẽ giúp bạn giải quyết vấn đề tracing id request và giúp chẩn đoán ứng dụng NodeJS của bạn dễ dàng hơn một chút.

Kết luận

Qua bài viết, bạn đã biết được cách tối ưu tracing request id với app NodeJS

Tham khảo thêm về NodeJS : Unit test là gì – Jest testing NodeJS cho người mới bắt đầu


Like it? Share with your friends!

1043
1.4k shares, 1043 points

What's Your Reaction?

hate hate
0
hate
confused confused
0
confused
fail fail
0
fail
fun fun
0
fun
geeky geeky
0
geeky
love love
0
love
lol lol
0
lol
omg omg
0
omg
win win
0
win