Ampliy GC(Garbage Collector)와 메모리 부족 이슈 해결하기

Amplify
이민석's avatar
Sep 05, 2024
Ampliy GC(Garbage Collector)와 메모리 부족 이슈 해결하기

개요

본 문서는 Next.js Amplify 빌드 중에 발생한 메모리 관련 이슈를 다루고 있습니다.

  1. 장애 해결 방법

  2. Node.js GC*, Scavenge, Mark-Sweep 이해

  3. Next.js GC Log 분석 기반으로 OldSpace Size 지정

에러 메세지

Amplify로 배포를 하던 와중 아래와 같은 에러가 발생했습니다.

2024-08-29T02:21:19.390Z [WARNING]: <--- Last few GCs --->
[4009:0x6e9c850] 53705 ms: Mark-sweep (reduce) 2045.1 (2082.7) -> 2044.8 (2083.4) MB, 565.3 / 0.0 ms (+ 72.8 ms in 20 steps since start of marking, biggest step 5.0 ms, walltime since start of marking 657 ms) (average mu = 0.239, current mu = 0.259) a[4009:0x6e9c850] 54513 ms: Mark-sweep (reduce) 2046.0 (2083.4) -> 2044.7 (2083.4) MB, 802.6 / 0.0 ms (average mu = 0.130, current mu = 0.008) allocation failure; scavenge might not succeed
<--- JS stacktrace --->

해당 이슈는 Node.js GC*의 OldSpace가 부족해서 발생한 문제로
문제가 발생한 dev 망의 OldSpace 크기를 증가시켜서 에러 해결했습니다.

NODE_OPTIONS="--max-old-space-size=4096"

이후 문제 발생 원인 및 할당할 OldSpace 계산을 위한 리서치 진행했습니다.

  1. 문제 발생 원인 분석을 위한 Node.js에서 GC, Scavnege, Mark-Sweep 개요

  2. 할당할 OldSpace 계산을 위한 Next.js에서 GC Log 확인하고 디버깅하기

Node.js에서 GC, Scavenge, Mark-sweep 개요

Node.js에서는 메모리 관리를 위해서 GC*를 사용하며,
내부적으로는 Scavenge*, Mark-Sweep* 등이 사용됩니다.

이 과정을 추적하기 위해서 --trace-gc 옵션을 사용할 수 있습니다.
실제 배포 중인 어플리케이션에 대해서 아래와 같이 --trace-gc를 사용해보았습니다.

node --trace-gc ./.next/standalone/server.js

그 결과 아래와 같은 GC 과정을 추적할 수 있게 되었습니다.

[10251:0x130008000]       32 ms: Scavenge 4.6 (4.8) -> 4.2 (5.8) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 

기준값

예시

실행 중인 프로세스의 PID

10251

JS 힙 인스턴스(Isolate)

0x130008000

프로세스가 시작된 이후의 시간(ms)

32ms

GC의 유형/단계

Scavenge

GC 전 사용된 Heap

4.6

GC 전 총 Heap

4.8

GC 후 사용된 Heap

4.2

GC 후 총 Heap

5.8

GC에 소요된 시간

(평균 mu = 1.000, 현재 mu = 1.000)

GC 이유

allocation falure;

Node.js의 GC*

Garbage Collector의 약자로 Trash talk: the Orinoco garbage collector를 참고해주세요.

Node.js의 Scavenge*

GC*는 Scavenge 작업을 통해서 GC* 대상이 아닌 Objects를 OldSpace로 승격시킵니다. 이렇게 승격된 Objects들은 Mark-Sweep 과정에서 빈 메모리로 치환될 수 있습니다.

전체 과정은 Sample Scavenge Senario를 참고해주세요.

Node.js의 Mark-Sweep*

Mark*와 Sweep으로 구분된 작업이 진행됩니다.
OldSpace의 Live Objects/Dead Objects를 구분하는 마킹 작업을 진행합니다.
Dead Objects들을 스캔하여 이들을 빈 메모리로 변환합니다.

전체 과정은 Mark State를 참고해주세요.

Node.js GC Logs 분석하기

실제로 빌드된 Next.js Application을 실행하면,
지속적으로 Scavenge 작업이 이루어지면서 점점 더 많은 Heap을 사용하다가
MarkSweep 단계에서 OldSpace의 Dead Objects가 수거되어 더 적은 Heap으로 감소되는 것을 볼 수 있습니다.

[11770:0x140008000]       21 ms: Scavenge 4.6 (4.8) -> 4.2 (5.8) MB, 0.2 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
[11770:0x140008000]       28 ms: Scavenge 5.1 (6.3) -> 4.8 (7.1) MB, 0.2 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
[11770:0x140008000]       35 ms: Scavenge 6.4 (7.7) -> 6.0 (10.4) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
[11770:0x140008000]       43 ms: Scavenge 8.1 (10.4) -> 7.1 (11.2) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
[11770:0x140008000]       65 ms: Scavenge 9.2 (11.6) -> 8.5 (12.6) MB, 2.7 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
[11770:0x140008000]       90 ms: Scavenge 9.9 (12.6) -> 8.8 (17.3) MB, 0.7 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
[11770:0x140008000]      113 ms: Scavenge 13.6 (19.1) -> 11.6 (20.3) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
[11770:0x140008000]      143 ms: Scavenge 19.4 (24.0) -> 17.3 (25.5) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
Listening on port 3000 url: http://localhost:3000
[11770:0x140008000]      150 ms: Mark-sweep 17.9 (25.5) -> 15.9 (34.2) MB, 1.4 / 0.0 ms  (+ 0.5 ms in 10 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 7 ms) (average mu = 1.000, current mu = 1.000) finalize incremental marking via stack guard; GC in old space requested
[11770:0x140008000]      273 ms: Scavenge 36.2 (45.2) -> 30.2 (45.2) MB, 3.1 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure; 
[11770:0x140008000]      288 ms: Mark-sweep 31.0 (45.5) -> 29.3 (63.2) MB, 2.0 / 0.0 ms  (+ 0.3 ms in 9 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 15 ms) (average mu = 0.984, current mu = 0.984) finalize incremental marking via stack guard; GC in old space requested
[11770:0x140008000]      332 ms: Scavenge 47.0 (64.7) -> 33.3 (64.7) MB, 0.6 / 0.0 ms  (average mu = 0.984, current mu = 0.984) allocation failure; 
[11770:0x140008000]      396 ms: Scavenge 48.5 (66.2) -> 35.8 (68.0) MB, 1.0 / 0.0 ms  (average mu = 0.984, current mu = 0.984) allocation failure; 
[11770:0x140008000]      430 ms: Scavenge 51.8 (69.2) -> 38.8 (71.0) MB, 0.6 / 0.0 ms  (average mu = 0.984, current mu = 0.984) allocation failure; 
[11770:0x140008000]      492 ms: Scavenge 54.3 (72.0) -> 41.2 (74.0) MB, 0.6 / 0.0 ms  (average mu = 0.984, current mu = 0.984) allocation failure; 
[11770:0x140008000]      522 ms: Scavenge 56.9 (74.5) -> 43.2 (76.2) MB, 0.6 / 0.0 ms  (average mu = 0.984, current mu = 0.984) allocation failure; 
[11770:0x140008000]      588 ms: Scavenge 59.1 (76.7) -> 45.4 (78.0) MB, 0.6 / 0.0 ms  (average mu = 0.984, current mu = 0.984) allocation failure; 
[11770:0x140008000]      618 ms: Scavenge 61.3 (78.9) -> 47.6 (80.7) MB, 0.8 / 0.0 ms  (average mu = 0.984, current mu = 0.984) allocation failure; 
[11770:0x140008000]      714 ms: Scavenge 67.4 (85.3) -> 55.5 (85.8) MB, 4.1 / 0.0 ms  (average mu = 0.984, current mu = 0.984) allocation failure; 
[11770:0x140008000]      800 ms: Mark-sweep 60.6 (87.0) -> 49.2 (87.1) MB, 3.0 / 0.0 ms  (+ 9.4 ms in 167 steps since start of marking, biggest step 1.5 ms, walltime since start of marking 13 ms) (average mu = 0.977, current mu = 0.976) finalize incremental marking via task; GC in old space requested
[11770:0x140008000]     8902 ms: Mark-sweep (reduce) 49.2 (87.1) -> 48.4 (52.7) MB, 4.9 / 0.0 ms  (+ 7.2 ms in 113 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 13 ms) (average mu = 0.998, current mu = 0.999) finalize incremental marking via task; GC in old space requested
[11770:0x140008000]     9523 ms: Mark-sweep (reduce) 48.5 (52.7) -> 47.4 (51.5) MB, 4.2 / 0.0 ms  (+ 12.9 ms in 136 steps since start of marking, biggest step 0.7 ms, walltime since start of marking 19 ms) (average mu = 0.994, current mu = 0.973) finalize incremental marking via task; GC in old space requested
[11770:0x140008000]    10151 ms: Mark-sweep (reduce) 47.4 (51.5) -> 45.7 (51.0) MB, 7.8 / 0.0 ms  (+ 17.2 ms in 128 steps since start of marking, biggest step 1.3 ms, walltime since start of marking 27 ms) (average mu = 0.987, current mu = 0.960) finalize incremental marking via task; GC in old space requested

최종적으로 Mark-Sweep이 완료되는 시점에는 51.0 MB가 되므로,
OldSpace의 크기를 50보다 낮게하면 에러가 발생하고 55보다 크게하면 에러가 나지 않을 것입니다.

  • 에러 발생

    node --trace-gc --max-old-space-size=50 ./.next/standalone/server.js
  • 정상 실행

    node --trace-gc --max-old-space-size=55 ./.next/standalone/server.js

즉 GC* Logs를 활성화하고 이를 분석하면
Node.js Application이 실행되기 위한 최소 OldSpace를 판단할 수 있습니다.
또한 이 값을 기준으로 GC*가 많거나 Overhead*가 발생하고 있는지 알 수 있습니다.

메모리 누수를 수정한 이후 Mark-Sweep이 더 적게 발생하고
GC 후 총 Heap이 더 작은 사이즈라면 메모리 사용량이 개선된 것입니다.


 

Next.js에서 GC Log 확인하고 디버깅하기

Next.js를 사용하게 되면 아래의 스크립트를 사용하게 됩니다.

next build
next start

따라서 build, start 단계에서 메모리 현황을 추적할 필요가 있습니다.
이 경우에는 --experimental-debug-memory-usage을 next.js 14.2.0 upper버전에서 지원하고 있습니다.

공식 문서에서는 다음의 명령어를 통해서 HeapProfile을 생성하는 것을 안내합니다.

node --heap-prof node_modules/next/dist/bin/next build

하지만 저희는 다음 명령어를 사용해서 Scanvege, Mark-Sweep을 확인하고자 합니다.

node --trace-gc node_modules/next/dist/bin/next build
node --trace-gc node_modules/next/dist/bin/next start

해당 내용을 기반으로 GC 후 총 Heap을 확인하면 다음의 결론을 얻을 수 있습니다.

Next.js Application Build에는 1617 * 1.1(여유) 크기의 OldSpace 필요
Next.js Application Start에는 48.2 * 1.1(여유) 크기의 OldSpace 필요

따라서 다음과 같은 스크립트를 지정하는 것이 옳아보입니다.

node --trace-gc --max-old-space-size=1780 node_modules/next/dist/bin/next build # 1778.1
node --trace-gc --max-old-space-size=53 node_modules/next/dist/bin/next start # 53.02

참고 자료

Share article
RSSPowered by inblog