## 概述 在 Node.js v14 的環境發現 CPU 使用量會隨時間升高，從 CPU metric 追查到使用 gdb 的情況下，發現是此版本 GC 的問題 ## 過程 某天在 Slack 收到 CPU 使用量過高的警報，發現 CPU `Busy System` 使用率隨時間逐漸升高 ![image](https://hackmd.io/_uploads/HykNjkiXkx.png) 進到機器看發現是某個 Container 內的 Process 造成，這個服務的執行方式有點不太正確，是 Container 內又包了 PM2，不過這不是造成這次 CPU 使用量高的原因 ![image](https://hackmd.io/_uploads/ryaWnyj7kl.png) ![image](https://hackmd.io/_uploads/ByU53ys71x.png) 一開始也懷疑是因為 Container 內包 PM2 或是使用 Alpine 造成的原因，但是拔除測試後並未排除，後來使用 `strace` 才發現有 `SIGILL` 發生，往下用 `gdb` 就抓到是V8 GC的問題，更新 Node.js 版本才能解決 ### Log #### Strace 因為是 CPU 是 System 的部分在高，追蹤 System call 的部分來確認真的是 System CPU 造成的 不過對追蹤是哪段程式碼造成的並沒有太大的幫助，頂多可以確認是底層溝通的問題 ``` --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPN, si_addr=0x5647acc40923} --- read(5, "*", 1) = 1 write(16, "h\31\346}\245\177\0\0\4\0\0\0\0\0\0\0", 16) = -1 EAGAIN (Resource temporarily unavailable) write(6, "*", 1) = 1 rt_sigreturn({mask=[]}) = 0 --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPN, si_addr=0x5647acc40923} --- read(5, "*", 1) = 1 write(16, "h\31\346}\245\177\0\0\4\0\0\0\0\0\0\0", 16) = -1 EAGAIN (Resource temporarily unavailable) ^Cwrite(6, "*", 1strace: Process 2792203 detached <detached ...> ``` #### gdb 在 `Strace` 有發現 `SIGILL`，那就可以用 `gdb` 來讓 Process 在 `SIGILL` 的時候停止並取得 backtrace 來確認是哪一段出問題 ```sh gdb -p <pid> handle SIGILL stop // 預設就是這個設定 bt ``` ``` Thread 1 "node /code/dist" received signal SIGILL, Illegal instruction. 0x00005653314a9923 in v8::base::OS::Abort() () (gdb) handle SIGILL stop Signal Stop Print Pass to program Description SIGILL Yes Yes Yes Illegal instruction (gdb) bt #0 0x00005653314a9923 in v8::base::OS::Abort() () #1 0x00005653326bff74 in V8_Fatal(char const*, ...) () #2 0x000056533199ccbe in v8::internal::Scavenger::Process(v8::internal::OneshotBarrier*) () #3 0x00005653319a466a in v8::internal::ScavengingTask::RunInParallel(v8::internal::ItemParallelJob::Task::Runner) () #4 0x00005653319292bc in v8::internal::ItemParallelJob::Run() () #5 0x00005653319a2100 in v8::internal::ScavengerCollector::CollectGarbage() () #6 0x000056533190c9fd in v8::internal::Heap::Scavenge() () #7 0x000056533191bb20 in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) () #8 0x000056533191c1ce in v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) () #9 0x0000565331920428 in v8::internal::Heap::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) () #10 0x00005653318dda07 in v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) () #11 0x0000565331ca779f in v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) () #12 0x000056533209c759 in Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_NoBuiltinExit () #13 0x0000565332104d80 in Builtins_Load_FastDoubleElements_0 () #14 0x0000000000000000 in ?? () (gdb) ``` ![image](https://hackmd.io/_uploads/rkmKFkomyl.png) ### 其他問題 #### Container 內包 PM2 基本上這樣包是沒必要的，除非是要把前後端包在一起之類的 Container 內包 PM2，最大最大的問題會造成在 Docker 的 Healthcheck 失效，因為在用 PM2 通常是要用 Cluster 功能 這 Cluster 會 把流量導向正常的 Instance，讓 Docker 的 Healthcheck 在有某一個 Instance壞掉的情況下無法偵測到 #### 底層 Node.js 使用的 Library `No such file or directory` 在 `lsof` process 時有發現一些 `No such file or directory` 的問題，可能是 Image版本導致，不過目前在服務運作上並沒有出現Exception，且在任何 Alpine 或 Debian 的發行版 Node.js Image 的不同框架都會發生 ``` ***@***:~$ sudo lsof -p 2792203 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME node\x20/ 2792203 root cwd DIR 0,63 4096 39334638 /code node\x20/ 2792203 root rtd DIR 0,63 4096 39347117 / node\x20/ 2792203 root txt REG 0,63 76743400 47612409 /usr/local/bin/node node\x20/ 2792203 root mem REG 0,63 47612400 /usr/lib/libgcc_s.so.1 (stat: No such file or directory) node\x20/ 2792203 root mem REG 0,63 47612402 /usr/lib/libstdc++.so.6.0.28 (stat: No such file or directory) node\x20/ 2792203 root mem REG 0,63 47612027 /lib/ld-musl-x86_64.so.1 (stat: No such file or directory) node\x20/ 2792203 root 0u CHR 1,3 0t0 5 /dev/null ```