環境
- 言語：node v14.7.0
- CPU
- AMD Ryzen 9 3900X 12-Core Processor
- Processer 24
- メモリ容量：62.8GB
- OS：Ubuntu 18.04.4 LTS (Bionic Beaver)
あらまし
メモリを64GB搭載しているUbuntu上で、 --max-old-space-size オプションによって最大消費メモリを48GBに拡張した状態でnodeを動かしたところ、プログラムの内容に依存して、48GBを使い切れる場合と、20GB程度を消費した時点でメモリエラーが発生する場合の2通りの挙動があった。
その原因はプログラムの動作の違いによるメモリアロケーションの仕方の違いにあり、メモリを使い切れないプログラムではマッピング数が超過することによりmmapシステムコールがENOMEMを発生させることによるものだった。
sudo sysctl -w vm.max_map_count=655300 コマンドによりシステムの最大マッピング数を拡張した結果、与えたメモリをプログラムが使い切れるようになった。
はじめに
消費メモリの表示
次のブロックコードは、bash上でnodeの消費メモリを表示するワンライナーを動かした様子である。
$ node -e 'console.log(process.memoryUsage().rss / 1024 / 1024 / 1024);'
0.02828216552734375
次のものは10,000,000個の数値の0で構成される配列を作った後で消費メモリを見た様子である。
$ node -e 'var a = Array.from({length: 10000000}, v => 0); console.log(process.memoryUsage().rss / 1024 / 1024 / 1024);'
0.10385513305664062
消費メモリは0.028GBから0.103GBに少し上がっている。
10メガ個の整数が70MB程度の消費を生み出したことになる。
--max-old-space-size を指定しないとメモリ上限がすぐに訪れる
では、0ではなく100個の0で構成された配列を生成したらどうだろうか。
$ node -e 'var a = Array.from({length: 10000000}, v => Array.from({length: 100}, v => 0)); console.log(process.memoryUsage().rss / 1024 / 1024 / 1024);'
この環境には64GB程度のメモリがあるので、物理的には足りそうな気がする。
しかし、nodeが5GB程度を消費した段階で次のようなエラーが出る。
$ node -e 'var a = Array.from({length: 10000000}, v => Array.from({length: 100}, v => 0)); console.log(process.memoryUsage().rss / 1024 / 1024 / 1024);'
<--- Last few GCs --->
[27037:0x648f650] 45191 ms: Scavenge 4093.1 (4100.7) -> 4093.0 (4101.5) MB, 5.7 / 0.0 ms (average mu = 0.125, current mu = 0.081) allocation failure
[27037:0x648f650] 45204 ms: Scavenge (reduce) 4094.0 (4105.5) -> 4094.0 (4106.2) MB, 5.6 / 0.0 ms (average mu = 0.125, current mu = 0.081) allocation failure
[27037:0x648f650] 45218 ms: Scavenge (reduce) 4095.1 (4100.5) -> 4095.0 (4103.7) MB, 6.2 / 0.0 ms (average mu = 0.125, current mu = 0.081) allocation failure
<--- JS stacktrace --->
FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
1: 0x9fd5f0 node::Abort() [node]
2: 0x94a45d node::FatalError(char const*, char const*) [node]
3: 0xb7099e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
4: 0xb70d17 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
5: 0xd1a905 [node]
6: 0xd1b48f [node]
7: 0xd294fb v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node]
8: 0xd2d0bc v8::internal::Heap::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node]
9: 0xcfb7bb v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) [node]
10: 0x1040c4f v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [node]
11: 0x13cc8f9 [node]
Aborted (core dumped)
Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory でGoogle検索すると、次のような --max-old-space-size でnodeが消費できるメモリの上限を拡張すればいいという記事が大量に得られた。
この環境には64GBのメモリがあるので、では48GBまで消費できるようにしてみよう。
$ node --max-old-space-size=$((1024 * 48)) -e 'var a = Array.from({length: 10000000}, v => Array.from({length: 100}, v => 0)); console.log(process.memoryUsage().rss / 1024 / 1024 / 1024);'
8.26059341430664
無事、8.2GBのメモリを消費したのち正常に終了した。
指定されたメモリを使い切れない
では、「100個の0で構成された配列」ではなく「1000個の空配列で構成された配列」を生成したらどうだろうか。
そもそも消費メモリは10倍になるはずなのでメモリ不足になるはずである。
更に0ではなくここでは空配列を生成してみる。
$ node --max-old-space-size=$((1024 * 48)) -e 'var a = Array.from({length: 10000000}, v => Array.from({length: 1000}, v => [])); console.log(process.memoryUsage().rss / 1024 / 1024 / 1024);'
予想では、48GBを使い切ってメモリ不足によるエラーで異常終了するはずである。
48GBを使い切る前にはガベージコレクションによって動作速度が極端に遅くなることも考えられる。
結果は、たったの16.8GBを消費した時点で次のようなエラーで終了した。
前節の結果により、 --max-old-space-size の効果は表れていることは判明している。
$ node --max-old-space-size=$((1024 * 48)) -e 'var a = Array.from({length: 10000000}, v => Array.from({length: 1000}, v => [])); console.log(process.memoryUsage().rss / 1024 / 1024 / 1024);'
<--- Last few GCs --->
[10261:0x648f730] 77051 ms: Scavenge 16379.4 (16414.4) -> 16377.4 (16428.1) MB, 32.2 / 0.0 ms (average mu = 0.794, current mu = 0.795) allocation failure
[10261:0x648f730] 77103 ms: Scavenge 16393.4 (16428.1) -> 16395.3 (16430.4) MB, 27.8 / 0.0 ms (average mu = 0.794, current mu = 0.795) allocation failure
[10261:0x648f730] 77189 ms: Scavenge 16395.3 (16430.4) -> 16393.6 (16441.6) MB, 86.3 / 0.0 ms (average mu = 0.794, current mu = 0.795) allocation failure
<--- JS stacktrace --->
FATAL ERROR: Scavenger: semi-space copy Allocation failed - JavaScript heap out of memory
Segmentation fault (core dumped)
また、何回か実行するとエラー文がランダムで次のものになることがあった。
$ node --max-old-space-size=$((1024 * 48)) -e 'var a = Array.from({length: 10000000}, v => Array.from({length: 1000}, v => [])); console.log(process.memoryUsage().rss / 1024 / 1024 / 1024);'
terminate called after throwing an instance of 'std::bad_alloc'
what(): std::bad_alloc
Aborted (core dumped)
どうして --max-old-space-size で48GBを指定しても16.8GBしか使っていない状態で終了するのだろうか？
どうすれば48GBを使い切ることができるのだろうか？
調査
48GBを使い切れるコードと使い切れないコード
次のコードは、メモリ消費量の表示回数を上げたものである。
$ node --max-old-space-size=$((1024 * 48)) -e 'Array.from({length: 10000}, v => { console.log(process.memoryUsage().rss / 1024 / 1024 / 1024); return Array.from({length: 1000000}, v => []); });'
実行するとひたすらメモリ消費量を表示し、20GB程度で異常終了した。
＜前略＞
20.046581268310547
20.084598541259766
20.122615814208984
20.160381317138672
terminate called after throwing an instance of 'std::bad_alloc'
what(): std::bad_alloc
Aborted (core dumped)
次のコードはそれを「空配列の配列の配列」ではなく「1の配列の配列」を生成するようにしたものである。
$ node --max-old-space-size=$((1024 * 48)) -e 'Array.from({length: 10000}, v => { console.log(process.memoryUsage().rss / 1024 / 1024 / 1024); return Array.from({length: 1000000}, v => 1); });'
このコードは20GBで止まらず、指定された約48GBのメモリを使い果たして終了する！
しかも消費メモリが46GBを超えたあたりから頻繁にガベージコレクションでカクつき、なかなか消費メモリが上がらない状態になったアキレスと亀。
＜前略＞
48.053977966308594
48.06153106689453
48.06904602050781
48.076324462890625
48.08384323120117
<--- Last few GCs --->
＜中略＞
<--- JS stacktrace --->
FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
1: 0x9fd5f0 node::Abort() [node]
＜中略＞
17: 0x1018255 v8::internal::Runtime_NewArray(int, unsigned long*, v8::internal::Isolate*) [node]
18: 0x13cc8f9 [node]
Aborted (core dumped)
変わったのはデータ構造の最深部が空配列か数値の1かだけ。
どちらも物理メモリがそもそも足りないので最終的に異常終了することには変わらない。
std::bad_alloc はC++のnewが失敗したときのエラーらしい
std::bad_alloc でGoogle検索すると、それがC++のnewから出されるものであることが分かった。
nodeはC++で書かれていて、newを行っている箇所があるということになる。
std::bad_alloc はC++のtry文で捕捉できるが、出る場所がnewという一般的なところであるだけに捕捉される個所とされない箇所の両方で発生する可能性があるのだろう。
それがエラー文がランダムで変わる原因と予想する。
straceで見ると、mmapがENOMEMというエラーを出していることが分かった
straceとはプロセスのシステムコールを出力できるコマンドである。
とりあえず次のようにnodeの前に置いて実行してみた。
$ strace node --max-old-space-size=$((1024 * 48)) -e 'Array.from({length: 10000}, v => { console.log(process.memoryUsage().rss / 1024 / 1024 / 1024); return Array.from({length: 1000000}, v => 1); });'
怒涛のログが出力されるが、その末尾は次のようになっている。
＜前略＞
mprotect(0x29960bbc0000, 262144, PROT_READ|PROT_WRITE) = 0
brk(0x1bf9a000) = 0x1bf9a000
mmap(0x2ebbbafc0000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x2ebbbafc0000
munmap(0x2ebbbb000000, 258048) = 0
mprotect(0x2ebbbafc0000, 262144, PROT_READ|PROT_WRITE) = 0
mmap(0x3ba59c200000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x3ba59c200000
munmap(0x3ba59c240000, 258048) = 0
mprotect(0x3ba59c200000, 262144, PROT_READ|PROT_WRITE) = 0
mmap(0x3f3009d40000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x3f3009d40000
munmap(0x3f3009d80000, 258048) = 0
mprotect(0x3f3009d40000, 262144, PROT_READ|PROT_WRITE) = 0
mmap(0x330b57380000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x330b57380000
munmap(0x330b573c0000, 258048) = 0
mprotect(0x330b57380000, 262144, PROT_READ|PROT_WRITE) = 0
mmap(0x207b9d440000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x207b9d440000
munmap(0x207b9d480000, 258048) = 0
mprotect(0x207b9d440000, 262144, PROT_READ|PROT_WRITE) = 0
mmap(0x300db2380000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x300db2380000
munmap(0x300db23c0000, 258048) = 0
mprotect(0x300db2380000, 262144, PROT_READ|PROT_WRITE) = 0
mmap(0x8e44e340000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x8e44e340000
munmap(0x8e44e380000, 258048) = 0
mprotect(0x8e44e340000, 262144, PROT_READ|PROT_WRITE) = 0
mmap(0x1a79a5c00000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x1a79a5c00000
munmap(0x1a79a5c40000, 258048) = 0
mprotect(0x1a79a5c00000, 262144, PROT_READ|PROT_WRITE) = 0
mmap(0x9abb4d00000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(0x9abb4d00000, 520192, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mprotect(0xafbb8382000, 86016, PROT_READ|PROT_WRITE) = 0
mprotect(0xafbb83c2000, 249856, PROT_READ|PROT_WRITE) = 0
mprotect(0xafbb8402000, 4096, PROT_READ|PROT_WRITE) = 0
mprotect(0xafbb8442000, 4096, PROT_READ|PROT_WRITE) = 0
mprotect(0xafbb8482000, 4096, PROT_READ|PROT_WRITE) = 0
mmap(NULL, 1040384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)
brk(0x1c0a2000) = 0x1bf9a000
mmap(NULL, 1175552, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(0x7efbe4000000, 67108864, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(NULL, 134217728, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(NULL, 67108864, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(NULL, 134217728, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(NULL, 67108864, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = -1 ENOMEM (Cannot allocate memory)
mmap(NULL, 1040384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)
futex(0x7efbfebab1a0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
write(2, "terminate called after throwing "..., 48terminate called after throwing an instance of ') = 48
write(2, "std::bad_alloc", 14std::bad_alloc) = 14
write(2, "'\n", 2'
) = 2
write(2, " what(): ", 11 what(): ) = 11
write(2, "std::bad_alloc", 14std::bad_alloc) = 14
write(2, "\n", 1
) = 1
rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
getpid() = 15400
gettid() = 15400
tgkill(15400, 15400, SIGABRT) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=15400, si_uid=1003} ---
+++ killed by SIGABRT (core dumped) +++
Aborted (core dumped)
ここで、以下の行によって、mmapという部分で ENOMEM というエラーが出ていることが分かる。
なぜメモリは余っているのに Cannot allocate memory なのだろうか。
mmap(NULL, 67108864, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = -1 ENOMEM (Cannot allocate memory)
ENOMEMが出る条件はメモリ不足およびマッピング数超過
mmapのmanに重要な情報が書いてあった。
ENOMEM
メモリーに空きがない、または処理中のプロセスのマッピング数が最大数を超過した。
マッピング数が最大数を超過した 場合、メモリが余っていてもENOMEMが出る。
出るエラー自体は共通のENOMEMなので、おそらくプログラムから見るとメモリ不足と区別できないだろう。
JavaScript heap out of memory というエラーメッセージになるのも納得できる。
sudo sysctl -w vm.max_map_count= で最大マッピング数を増加できる
次の場所からマッピング数の上限を増やす方法が得られた。
sysctl vm.max_map_count で現在の値が分かる。
sudo sysctl -w vm.max_map_count=65536 で値を設定できる。
変更はシステム全体に影響し、再起動で元に戻るらしい。
対策
vm.max_map_count の値を現在の10倍にしてみた。
$ sysctl vm.max_map_count
vm.max_map_count = 65530
$ sudo sysctl -w vm.max_map_count=655300
vm.max_map_count = 655300
結果
対策後、再び空配列の配列の配列を生成するコードを起動してみた。
$ node --max-old-space-size=$((1024 * 48)) -e 'Array.from({length: 10000}, v => { console.log(process.memoryUsage().rss / 1024 / 1024 / 1024); return Array.from({length: 1000000}, v => []); });'
その結果、期待通り与えた約48GBのメモリを最後まで使い切ってから異常終了するようになった。
＜前略＞
48.66949462890625
48.756752014160156
48.79401397705078
48.831199645996094
48.86867141723633
<--- Last few GCs --->
＜中略＞
<--- JS stacktrace --->
FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
1: 0x9fd5f0 node::Abort() [node]
＜中略＞
11: 0x13cc8f9 [node]
Aborted (core dumped)
あとがき
結局node固有の問題ではなかった。
C++の問題ですらなかった。
当初は「16.8GB」で止まるという点からヒープサイズが別に制限されていたり、GCの関係でメモリの使い方がそういうものなのかと考えたり、C++で22億個のオブジェクトをnewすると32ビット整数が足りなくなってnewに失敗するのかもしれないとか考えていた。