[프론트엔드]Node.js 메모리 누수 탐지하기

*사내 내부 공유를 위해 작성되었던 글이기 때문에 내부 코드를 유추할 수 있는 내용은 일부 숨김 처리하거나 의사 코드로 처리하였습니다.

 

안녕하세요, 빅픽처 인터랙티브 프론트엔드(Frontend) 챕터 소속 개발자 박성렬입니다.

저희 개발팀은 올해(2021년) 하반기에 FE 리뉴얼 작업을 진행하고 있습니다. 기존에 운영하던 웹앱은 Vue Single Paged App(이하 SPA) 기반 앱에 정적으로 생성된 페이지 몇 개를 일부 섞은 일종의 하이브리드 SPA+SGP(이하 Statically Generated Page) 앱이었는데요, 이번에 서버 사이드 렌더링(Server Side Rendering, SSR)로 전환하며 널리 알려진 SSR 도구를 사용하지 않고 직접 개발하는 시도를 진행했습니다. 그 덕분에 매우 퍼포먼스가 빨라졌으나, 예상치 못한 문제와 마주하게 되었습니다.

 

리뉴얼 앱에 드디어 메모리 누수가 발생했습니다. 앱의 사이즈가 커질 때마다 가끔씩 발생하는 문제인데요, 재미있게도 이번에는 브라우저 내부가 아닌 SSR 앱에서 발생했기 때문에 그 원인에 대해서 알아보고 다른 구성원분들께서도 어떤 식으로 문제를 해결할 수 있는지 알려드리면 좋을 것 같다는 생각이 들었습니다. 발생한 메모리 누수를 어떻게 탐지하고, 대응했는지 알려드리도록 하겠습니다.

조우

작업 도중 계속 앱을 배포하고 새로고침하다보니 우연히 브라우저에서 HTTP 코드 500대 오류를 보게 되었습니다. 처음에는 별로 대수롭게 생각하지 않았다가, 잦은 QA로 인해서 작업량이 많아지자 에러를 몇 번 더 보게 되었습니다. 로컬 개발환경(맥북)에서 재현하기 위해 로컬 인스턴스를 띄워놓고 접속해보니 같은 오류가 좀처럼 발생하지 않았습니다.

 

다소 마음이 급해져서 백엔드팀에 요청하여 Kibana(이하 키바나)에 있는 로그를 확인해 보았습니다. 몇 십분 단위로 반복하여 꾸준하게 500에러가 발생하고 있었습니다. 오류의 발생 간격이 다소 간헐적 이었기 때문에 개발팀 아무도 눈치를 채지 못한 상황이었습니다. 키바나에는 node.js(이하 노드)용 로깅 라이브러리(winston)가 연결되어 있어서 대략적인 에러는 확인할 수 있었지만, 구체적인 에러를 확인하기 위해 좀더 자세한 로그를 요청했습니다.

 

아래는 에러 발생 시점에 확인된 로그 메시지입니다.

<--- Last few GCs --->

[7:0x556146daefc0]   978803 ms: Mark-sweep 970.7 (1001.0) -> 970.6 (1001.0) MB, 1942.3 / 0.0 ms  (average mu = 0.083, current mu = 0.000)
allocation failure scavenge might not succeed
[7:0x556146daefc0]   980593 ms: Mark-sweep (reduce) 970.6 (1001.0) -> 970.3 (1000.5) MB, 1790.3 / 0.0 ms  (average mu = 0.044, current mu = 0.000)
last resort GC in old space requested
FATAL ERROR:
Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory

메시지에서 볼 수 있듯, 메모리를 비워주는 기능을 하는 Garbage Collector(이하 GC)에서 에러가 발생하고 있었습니다. 다시말해, 메모리 누수 문제가 있었습니다.

재현

메모리 누수 탐지의 첫번째는 비교할 수 있는 정량적인 수치 자료를 확보하는 것입니다. 제3사에서 제공하는 일반적인 어플리케이션 퍼포먼스 모니터링 도구(Application Performance Monitoring tools, 이하 APM)나 healthcheck를 위한 도구로는 별도의 설정 없이 노드의 내부를 관찰하기 어렵기 때문에, 힙 메모리 상태를 좀 더 정밀하게 감지할 수 있는 별도의 모니터링 도구를 설치합니다.

• express-status-monitor(github)

$ yarn add express-status-monitor

// server/index.js
server.use(require('express-status-monitor')());
// 설치 후 $HOST/status 에 접근 가능

설치 후에 해당 도구에서 제공하는 페이지로 접근하여 메모리 상태를 확인해 보았습니다.

http://localhost:xxxx/status에서 확인한 모니터링 상태.

CPU 점유율과 응답시간에는 큰 변화가 없으나, 힙 메모리와 전체적인 메모리 사용량이 계속 증가하고 있는 것을 확인했습니다.

 

가장 우려가 되는 것은 그 증가 폭이었는데, 일반적으로 메모리 증가 폭이 기가바이트 이하라면 노드에서 최대 램 허용량을 늘려서 임시변통할 수 있지만, 불과 수 십분동안만 켜 놓아도 금방 수 백 mb~1gb 정도의 용량에 도달하는 것을 확인했습니다. 인스턴스에 충분히 부담이 갈 수 있는 용량이라 좀더 빠른 대처가 필요했습니다.

 

우선은 임시변통을 하지 않고 더욱 확실한 스트레스 테스트를 하여 서버 로그에서 보았던 에러를 재현해 보기로 했습니다.

기본적인 sh 빌트인 프로그램을 먼저 이용해 보았습니다.

# 쿼리값을 1 부터 1000까지 순환하며 요청한다
$ curl http://localhost:XXXX?[1-1000]

메모리는 똑같이 기하급수적으로 증가했는데, 시간이 지나도 원하는 오류가 쉽게 나타나지 않았습니다. 아무래도 빌트인 프로그램이다보니 싱글쓰레드이고, 속도가 느려서 그런 것 같았습니다.

 

멀티 쓰레드로 되어있고 스트레스 테스트에 좀 더 최적화 되어있는 siege 로 다시 스트레스 테스트를 시도했습니다.

• siege(github)

# siege를 brew로 설치한다
$ brew install siege
# 똑같은 요청을 1000회 반복
$ siege -r 1000 http://localhost:XXXX
siege aborted due to excessive socket failure; you
can change the failure threshold in $HOME/.siegerc

Transactions:		        9558 hits
Availability:		       90.25 %
Elapsed time:		      122.59 secs
Data transferred:	     4222.31 MB
Response time:		        0.29 secs
Transaction rate:	       77.97 trans/sec
Throughput:		       34.44 MB/sec
Concurrency:		       22.39
Successful transactions:        9558
Failed transactions:	        1032
Longest transaction:	       19.02
Shortest transaction:	        0.00

다행스럽게도 약 122초만에 똑같은 에러 메시지가 나오면서 500에러가 발생했습니다. 이제 재현이 가능해졌기 때문에 원인만 발견하면 됩니다.

 

위의 보고서에서는 가용률이 90%로 나오는데, 즉 나머지 10%의 요청이 실패한 것이라고 보면 됩니다. 노드의 에러 메시지를 보지 않고서도 문제가 발생했음을 알 수 있습니다.

원인 분석

클라이언트 전용 렌더 무시

라이브러리의 종류를 불문하고 SSR에서 일어나는 가장 큰 오류유형은 클라이언트 전용 렌더구간을 설정하지 않는 것입니다. 여기에도 몇 가지 세부 유형이 있습니다.

• window 나 document 같은 변수는 브라우저에서만 접근이 가능하기 때문에 노드에서 접근하려고 하면 오류가 발생
• 서버 코드에서 타이머 관련(setInterval, setTimeout) 코드를 실행시켜서 서버의 백그라운드 프로세스에서 메모리를 낭비
• 클라이언트와 서버 환경이 다름에도 불구하고 최상위 스코프에 전역 변수를 설정

이럴 때 아래처럼 별도의 wrapper 함수나 컴포넌트 등을 이용해 서버 렌더 과정에서만 클라이언트 전용 컴포넌트를 가리는 방식으로 대응합니다.

// Nuxt.js(Vue)의 경우
<client-only>
  <ClientOnlyComponent />
</client-only>

// Next.js(React)의 경우
const ClientOnlyComponent = dynamic(() => import('../components/clientOnlylComponent'))

<div>
  <ClientOnlyComponent />
</div>

공교롭게도 확인 결과 리뉴얼중인 부분에도 타이머가 적용된 carousel, 애니메이션 슬라이더 등이 있었고 이를 전용 wrapper로 서버에서 렌더하지 않도록 바로잡아 보니 메모리 증가율이 눈에 띌 정도는 아니지만 다소 감소하는 것을 확인했습니다. 그러나 그 감소폭이 크지 않아 크게 신경쓸 정도는 아닌 것 같았습니다. 일단 실질적인 원인은 아니라고 보고 그래프는 포함하지 않았습니다.

 

잘못된 클로저

소거법을 이용해 여러가지 방법으로 확인해 보았습니다.

 

재귀 의존(Cyclic Dependency)에도 이슈가 있어서 처리해 보았으나 메모리에는 큰 영향을 주지 않았습니다.

페이지도 하나하나씩 지워보았으나 뚜렷한 성과가 없었습니다. 아무 페이지를 로드하지 않은 상태에서도 똑같이 힙 메모리가 증가하였기 때문에 앱의 진입 과정(entry)에 이슈가 있음을 예상했습니다.

// 라우터 코드
const getRoutes = async () => [
  // 기존 라우트는 주석처리하고, 빈 컴포넌트 집어넣음
  { path: '/', name: 'Home', component: EmptyComponent }
  // {
  //   path: '/',
  //   name: 'Home',
  //   meta: {id: 0},
  //   component: Home,
  // },
  // 기존라우트설정() 이 뒤에 이어지는데, 위처럼 모두 주석처리합니다
]

현재 리뉴얼중인 프로젝트의 렌더 진입 과정은 아래와 같습니다.

웹팩(webpack)을 통하여 번들링 되는 코드는 크게 두 가지로 나뉘어집니다. 라이브러리, 컴포넌트 코드가 있습니다. 이것을 express.js에서 VueSSR 전용 라이브러리를 통하여 가져와서 렌더합니다. 살펴보니 express.js쪽 코드는 분량이 많지 않았습니다.

 

그래서 모든 페이지를 지워버리고 빈 페이지만 하나 심어서 컴포넌트 코드를 전부 제외해 보았습니다.(빨간색으로 표시한 부분) 위의 도식처럼 컴포넌트 코드를 모두 제거했는데도 문제가 발생한다면, 라이브러리 코드에 문제가 있는 것이 됩니다.

 

코드에서 본 진입 과정은 또 아래와 같습니다. 원래 코드는 다소 복잡하고 익명 함수를 포함하고 있기 때문에, 쉽게 알아볼 수 있도록 간단한 이명(alias)을 부여했습니다.

 

// Vue.js를 랩핑하고 있는 최상단 코드(app.js)
import SomeLib // ...
const async createApp(context) => {
  app = new Vue({ SomeLib, /* ... */ })
  return app
}

// 클라이언트 및 서버 Vue.js 엔트리 코드(app.js 보다 상단에 위치하며, 서버-클라이언트 여부에 따라 다르게 동작)
const bundledEntry (context) => {
  return new Promise((resolve ,reject) => {
    const app = await createApp(context);
    resolve(app)
  })
}

// 서버: express.js용 코드(server/index.js)
const renderer = createRenderer(bundledEntry)
server.get('*', (req, res) => {
  renderer.render(context, (err, html) => {
    res.end(inject(html, context))
  })
})

 

여기서 눈여겨 볼 부분은, 진입과정이 모두 함수로 되어있다는 점입니다. 그 이유는 이 작업이 노드의 요청 핸들러 내부에서 이루어져야 하기 때문입니다. 요청이 종료되면 마찬가지로 해당 핸들러 함수가 종료되어야 합니다. 만약 요청을 반환하고 페이지 렌더링이 끝났는데도 함수가 종료되지 않으면 그것이 곧 메모리 누수가 됩니다.

 

위의 순서도를 다시 자바스크립트의 함수 클로저(Closure)의 관계로 나타내면 아래와 같이 됩니다. 클로저란 닫다(Close)라는 말에서 추측할 수 있듯이, 어떤 변수를 스코프 내에 가지고 있어서 그 변수의 생명주기를 통솔할 수 있는 함수를 뜻합니다.

 

위의 함수 f(x)에서 a는 연산이 끝나면 더 이상 필요 없기 때문에 기억에서 버려도 됩니다. 프로그램도 마찬가지입니다. 위의 예시에서 볼 수 있는 bundledEntry(), createRenderer(), SomeLib() 함수 내부에서 const, let 또는 var로 초기화된 함수들은 일종의 운명 공동체가 됩니다.

 

그런데 이때 외부의 스코프를 클로저로 가진 함수(외부에서 초기화된 함수)가 함수 내부로 들어오면 해당 함수는 영원히 종료되지 않습니다. 이 함수를 혼자서는 닫을 수 없기 때문입니다.

// Somelib.js
// 싱글톤이면서, 클로저가 없는 변수
function SomeFunction() {
/* ... */
}

export default SomeFunction();

자바스크립트 v8 엔진은 GC를 이용해 사용하지 않는 힙 메모리만 자동으로 정리할 수 있습니다. 만약 사용하고 있는 힙 메모리를 정리하면 무슨 오류가 발생할지 모르기 때문입니다. 부모 함수(스코프, 클로저)가 여러개인 변수는 사용하고 있는 여러개의 함수가 모두 종료되기 전까지 GC가 마음대로 정리할 수 없습니다.

 

크롬 디버깅 도구를 이용해서 힙 메모리 상태를 확인해보았습니다.

$ VUE_APP_ENV=local node --inspect server
# 이후에 크롬에서 chrome://inspect로 접근

 

아래의 커맨드로 테스트해 보았습니다.

# 10개 동시접속을 6번 반복
$ siege -c 10 -r 6 http://localhost:XXXX

앱을 최초로 구동한 뒤(a)에 힙 메모리 스냅샷을 저장하고, 동시접속 요청을 날린 후(b)에 다시 힙 메모리 스냅샷을 저장하여 그 차이값(Delta)을 비교했습니다.

 

기존 힙 메모리 덤프 결과

기존에 요청이 발생한 직후 힙 메모리에서 delta를 살펴보니 GC를 통해 정리된 메모리는 거의 없고, 계속 증가(+)만 한 것을 알 수 있습니다.

 

제거하기로 한 첫번째 목표는 서비스 모듈입니다. 컴포넌트가 아니면서, vue 앱을 초기화하는 순간에 import가 발생하면서 클로저가 유실된 코드를 암묵적으로 가져올 확률이 가장 높습니다.(쉽게 말하면 노드 서버의 GET 요청 함수 스코프 바깥에서 import가 많이 발생하는 부분입니다) 따라서 이 코드를 제거하고 확인해봤습니다.

// 서비스 코드
import SomeLib from '@/utils/SomeLib'; // <-- 보통 이 라이브러리에서 의도하지 않은 싱글톤들이 많습니다.
// ... 그 외 각종 라이브러리
class SomeService { /* ... */ };
export default SomeService;

// Vue.js를 랩핑하고 있는 최상단 코드(app.js)
import SomeService from '@/services/SomeService';
const async createApp(context) => {
  app = new Vue({ SomeLib, /* ... */ })
  app.prototype.service = new Service(); // <-- 각종 의존성을 많이 품고 있는 서비스 위주로 주석처리해보았습니다.
  return app;
}

// 클라이언트 및 서버 Vue.js 엔트리 코드(app.js 보다 상단에 존재하며, 클라이언트 및 서버에 따라 다르게 사용되는 코드)
const bundledEntry (context) => {
  return new Promise((resolve ,reject) => {
    const app = await createApp(context);
    resolve(app);
  })
}

 

원인 삭제 후 힙 메모리 덤프 결과

Mapping으로 나타나고 있는 부분은 거의 개발환경에서 소스맵(sourcemap)을 제공하며 발생한 내용입니다. 그 외의 힙 메모리는 모두 차이값이 현저하게 감소한 것을 볼 수 있습니다. GC가 작동했기 때문입니다. 페이지(컴포넌트)만 지웠을 때에는 델타값이 별로 감소하지 않습니다.

 

해당 모듈은 현재 개발단계에서 매우 중요하기 때문에, 모든 내용을 삭제할 수는 없습니다. 좀더 명확한 타겟을 찾기 위해 해당 모듈 안의 서브 모듈들을 하나하나씩 소거법으로 삭제해보면서 메모리가 줄어드는 순간을 찾아보기로 했습니다. 서비스를 하나 하나씩 삭제할 때에는 별로 메모리가 줄어들지 않다가, 특정 코드를 하나 제거하자 갑자기 메모리의 증가율이 절반 정도로 줄어들었습니다.

GC 동작을 확인하기 위해 해당 구문을 주석처리한 상태를 그대로 두고 시간별 로그를 분석해봤습니다.

어느정도 시간이 지나자 GC가 동작하여 힙 메모리의 점유율이 실제로 줄어들고 일정한 상태로 유지되는 것을 볼 수 있습니다. 기존에는 요청이 없는 상태에서도 증가만 하고 힙 메모리가 증가만 하고 유지되거나 감소하는 일은 발생하지 않았습니다. 메모리 누수가 부분적으로 해결된 것으로 보입니다. 증가폭도 거의 절반 정도로 감소했습니다. 좀더 큰 규모로 스트레스 테스트를 해볼 경우 메모리의 증가가 여전히 있어서, 일부 구간에서 문제가 잔존하고 있지만, 대략적인 단서를 찾았다고 할 수 있습니다.

 

조금 더 시간을 들여 팀에서 확인해본 결과, 특정 라이브러리에서의 플러그인 인스톨 처리 과정에서 스코프 이슈가 있었기 때문이었습니다. 이 부분에 대해서는 민감 정보일 수 있어 언급하지 않습니다. 이 글은 메모리 누수를 어떠한 과정으로 탐지하고 대응하는가에 대해 설명하는 글로 이해해 주시면 될 것 같습니다.

소감

기존에 알려진 SSR용 라이브러리(Next.js, Nuxt.js)를 사용해서 개발을 할 때에는 정해진 스코프 안에서만 개발하기 때문에 메모리 누수의 영역이 비교적 분명했었는데, 커스텀한 도구에서 개발하다보니 메모리 누수를 찾기가 다소 어려웠습니다. 그러나 한 편으로는 SSR 메모리 누수의 또다른 유형과 문제해결을 체험할 수 있어서 좋은 경험이었던 것 같습니다.

 

그 외에 주의할 점

• 슬라이더 등 사용자 동작이 많고 뷰포트의 영향을 받기 쉬워 서버에서 렌더시 오동작이 예상되는 코드는 반드시 <client-only /> 로 감싸주세요
• SSR 개발환경에서는 vue 전용 모드 외에도 꼭 빌드를 하고 express 서버 코드를 함께 서빙하는 SSR 모드를 실행시켜 노드 서버 코드에 이상이 없는지 확인해주세요
• 서버에 혼입되는 코드는 반드시 인스턴스가 아닌 함수 또는 클래스 형태로만 import 해 주세요
• 여러 종류의 메모리 누수 유형에 익숙해질 필요가 있습니다: Array, Dependency Injection, Closure, Node Error