Express 디버깅 — DEBUG 변수로 내부 로그 보기

Express 앱이 예상대로 동작하지 않을 때, 어디서 문제가 생겼는지 눈으로 확인하고 싶어져요. Express는 DEBUG 환경 변수를 설정하면 내부 로그를 모두 볼 수 있게 해 줘요. 이렇게 하면 라우팅, 미들웨어, 애플리케이션 설정이 어떤 순서로 처리되는지 단계별로 추적할 수 있어요.

출처: Debugging Express · Express.js

Express가 쓰는 모든 내부 로그를 보려면 앱을 실행할 때 DEBUG 환경 변수를 express:*,router,router:*로 설정하면 돼요. 라우팅은 별도의 router 패키지가 처리하므로, 그 로그는 router 네임스페이스 아래에 있고 express:*에는 포함되지 않아요.

$ DEBUG=express:*,router,router:* node index.js

Windows에서는 대응하는 명령을 써요.

> $env:DEBUG = "express:*,router,router:*"; node index.js

JSON body 파서와 마운트된 라우터를 가진 작은 앱에서 이 명령을 실행하면 다음과 같은 출력이 나와요.

const express = require('express')

const app = express()
app.use(express.json())

const users = express.Router()
users.get('/', (req, res) => {
  res.json([])
})

app.use('/users', users)

app.get('/', (req, res) => {
  res.send('Hello World!')
})

app.listen(3000)

실행하면 앱이 시작될 때 이렇게 설정 로그가 찍혀요.

$ DEBUG=express:*,router,router:* node index.js
 express:application set "x-powered-by" to true +0ms
 express:application set "etag" to 'weak' +3ms
 express:application set "env" to 'development' +1ms
 express:application set "query parser" to 'simple' +0ms
 express:application set "subdomain offset" to 2 +1ms
 express:application set "trust proxy" to false +0ms
 ...
 router:route get / +1ms
 router:layer new '/' +1ms

그리고 요청이 앱에 들어오면, Express 코드에 지정된 로그가 보여요.

 router dispatching GET /users +712ms
 router jsonParser : /users +1ms
 router trim prefix (/users) from url /users +2ms
 router router /users : /users +0ms
 router dispatching GET / +0ms

router 구현에서만 로그를 보려면 DEBUG 값을 router,router:*로 설정해요. 마찬가지로 애플리케이션 구현의 로그만 보려면 DEBUG를 express:application 등으로 설정해요.

이 방식은 "요청이 어느 미들웨어를 지나 어떤 순서로 라우트에 도달했는지"를 가시적으로 보여주는 강력한 디버깅 도구예요. 복잡한 라우팅 스택에서 요청이 엉뚱한 곳으로 가거나, 미들웨어가 예상 밖의 순서로 실행될 때 특히 유용해요.