Back to Articles
etc회사이직면접

CLS에 대해 알아보자

HTTP Request ID 추적하기 in Node.js

2026.06.103 min read변경연
CLS에 대해 알아보자
author
postNo
status
thumbnail
description
category
tags
createdAt
updatedAt
만약 Node.js를 이용하여 백엔드를 개발한다면 HTTP request 로그를 추적하는것이 얼마나 어려운지 알것입니다.
보통 당신의 로그는 이렇게 나올거에요.
[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:
...
로그는 여러명의 호출로 인해 같은 로그가 뒤섞여 있습니다. 어떤것들이 같은 Request인지 알아보기 힘들죠.
HTTP Request추적을 위해 아마 다음과 같은 로그를 원할거에요.
[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:
...
로그를 보면 [request-id:*] 라고하는 식별자가 있습니다. 이 식별자를 통해 같은 사용자의 요청인지에 대한 필터링이 가능합니다.
HTTP통신을 하는 애플리케이션의 경우 한 체인에 속한 모든 마이크로서비스에서 생성된 로그를 취합할 수 있습니다.
개발자로서 추적, 로깅하고 Request Id를 생성하고 자동으로 출력하고 싶을것입니다. 하지만 불행히도 Node.js에서는 이것이 조금 힘듭니다.
이 문제를 해결하기 위한 해결책에 대해 얘기해보고자 합니다.
OK, But 이것이 정말 문제인가요?
JVM과 Java Servlet과 같은 다양한 플랫폼과 언어에서는 이는 큰 문제가 되지 않습니다.
왜냐하면 이는 HTTP서버가 멀티쓰레드와 블로킹 I/O기반으로 만들어지기 때문입니다. 이 경우 Request Id를 추적하기 위해서는 쓰레드에 식별자를 넣게 되면
자연스럽게 HTTP Request Id의 추적이 가능합니다. 그리고 이상적이지는 않지만 TLS (Tread-Local Storage)를 통해 해결해볼 수 있습니다. TLS는 기본적으로 키-값 쌍을 이루어 저장하고 검색하는 방법입니다. 쓰레드마다 각각 생성된 Request Id를 TLS를 통해 취합할 수 있는것이죠.
하지만 Node.js는 이벤트 루프 기반의 비동기적 특성으로 인해 TLS를 사용할 수 없습니다. 왜냐하면 Java Script는 단일 쓰레기이기 때문이죠.
만약 이런경우 Request Id를 추적하고 싶다면, Request에서 처리되는 모든 Context 객체를 넘겨주어야 합니다.
이는 Express에서 다음과 같은 형태가 될것입니다.
'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')
})
예제에서 req객체를 fakeDbAccess 에 넘겨줬고, 그로 인해 Request Id를 남기는것이 가능해졌습니다. 이 방법은 Routes와 모듈이 훨씬 많은 코드가 지저분해지고, 에러가 많이 발생할 수 있습니다.
Node.js 커뮤니티에서는 TLS를 대체할 방법들을 고민해왔고, 가장 좋은 대안으로는 Continuation-Local Storage (CLS)가 있습니다.
CLS로 구원을.
CLS는 라이브러리입니다. 이는 다음과 같이 CLS를 정의합니다.
Continuous-Local Storage는 스레드 프로그래밍에서 thread-local-storage 처럼 작동하지만, 스레드 대신 노드 스타일의 콜백 체인을 기반으로 합니다.
(Continuation-local storage works like thread-local storage in threaded programming, but is based on chains of Node-style callbacks instead of threads.)
이 라이브러리의 API를 확인해보면 JAVA TLS와 비교했을 때 더욱 복잡한것을 볼 수 있습니다. 하지만 핵심은 비슷합니다. Context 객체를 일련의 체인에 연결하여 나중에 접근할 수 있게 하는 것입니다.
CLS는 Node.js >= 8.2.1부터는 node 내장 API인 async_hooks를 사용합니다. API가 여전히 실험적이기는 하지만, polifill을 사용하는것 보다는 훨씬 좋습니다.
CLS를 알게 되었으니, 이제 앱 로그에서 Request Id를 추적하는 방법을 살펴보겠습니다.
여러가지 오픈코드들이 많습니다. Hello-CLS, cls-rtracer 등
예제에서는 cls-rtracer를 통해 Express를 구성하였습니다.
'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')
})
이는 다음과 같은 로그를 생성할 것입니다.
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
rTracer.expressMiddleware()함수 호출로 생성 된 Express 미들웨어를 생성하고, 이를 rTracer.id() 호출로 Request Id를 얻고 있습니다.
정말 간단하게 HTTP Request Id를 추적할 수 있게 되었습니다.
Async Hooks는 퍼포먼스의 문제가 있습니다. Node 14 에서 이는 개선된다고 하니 Node14를 한번 더 살펴보아야 겠습니다.

Reference

Buy me a bear!If you like this post..