บั๊กของ Node.js ที่ระบบมอนิเตอร์ของคุณมองไม่เห็น

ระบบ Health check บอกว่าทุกอย่างปกติดี ใช้เวลาเพียงหนึ่งมิลลิวินาที แต่เมื่อทราฟฟิกเพิ่มขึ้น อยู่ดีๆ ค่า p99 latency ก็พุ่งขึ้นไปถึง 400ms คุณลองเช็กแดชบอร์ดดู ทุกอย่างก็ยังขึ้นสีเขียวอยู่

การใช้งาน CPU อยู่ในระดับปานกลาง Event loop lag ก็คงที่ หน่วยความจำ (Memory) ก็ปกติดี APM ของคุณแสดงให้เห็นว่ามี request ที่ช้า แต่กลับไม่บอกเลยว่าเพราะอะไร ไม่มีการเรียกฐานข้อมูลที่ล่าช้า และไม่มี error ใดๆ เกิดขึ้น

เวลาที่เสียไปนั้นเกิดขึ้นใน libuv thread pool

การทำ Observability มาตรฐานของ Node มักจะมุ่งเน้นไปที่ event loop แต่ thread pool นั้นเป็นคิวที่แยกต่างหาก ซึ่งอยู่นอกเหนือขอบเขตที่คุณจะตรวจพบได้ง่ายๆ

Node รัน JavaScript บน event loop และจะส่งงานหนักๆ ไปยัง libuv thread pool ซึ่งรวมถึง:

  • งานเกี่ยวกับ Filesystem (fs.readFile, fs.writeFile).
  • งานด้าน Crypto (bcrypt, scrypt, pbkdf2).
  • การบีบอัดข้อมูล (zlib gzip, deflate).
  • การทำ DNS lookups (dns.lookup).

โดยค่าเริ่มต้น pool นี้จะมีเพียง 4 threads เท่านั้น ไม่ว่าเครื่องของคุณจะมี CPU กี่ core ก็ตาม

4 threads นั้นไม่เพียงพอ และนี่คือ 3 สถานการณ์ที่ทำให้ pool เกิดปัญหา:

  1. Bcrypt ตอนล็อกอิน: การทำ bcrypt hash เพียงครั้งเดียวอาจใช้เวลาถึง 250ms หากมีคนล็อกอินพร้อมกัน 4 คน ทุก slot จะเต็มทันที คนที่ 5 ที่เข้ามาจะต้องรอในคิว และต้องเสียเวลาไปอีก 250ms เพียงเพื่อที่จะเริ่มทำงาน ส่งผลให้ latency ของคุณเพิ่มขึ้นเป็นเท่าตัว

  2. การทำงานกับ gzip ขนาดใหญ่: การบีบอัด response ขนาดใหญ่จะจอง slot ใน pool ไว้ หากมี 4 request ทำแบบนี้พร้อมกัน งานอื่นๆ ทั้งหมดจะต้องรอ ทั้งการทำ DNS lookups และการอ่านไฟล์จะติดค้างอยู่ในคิว

  3. การทำ DNS lookups: แอป Node ส่วนใหญ่มักใช้ dns.lookup ซึ่งเป็นการเรียกใช้ system call แบบ blocking และจะส่งงานนี้ไปที่ pool หากเครือข่ายของคุณมีปัญหาเพียงเล็กน้อย การทำ lookup เหล่านี้จะทำให้ pool ทั้งหมดหยุดชะงัก

request ที่ติดอยู่ใน pool queue นั้นตรวจจับได้ยากมาก เพราะมันไม่ได้ใช้ CPU และไม่ได้รัน JavaScript แต่มันแค่ "จอดรอ" อยู่เฉยๆ

วิธีการค้นหา:

หากค่า p99 latency ของคุณสูงขึ้นเมื่อมีโหลดเข้ามา แต่ event loop lag ยังคงคงที่ ให้ลองเช็กที่ pool

วิธีทดสอบที่เร็วที่สุด: เพิ่ม UV_THREADPOOL_SIZE โดยลองตั้งค่าเป็น 64 ใน environment ของคุณแล้ว restart หาก latency ลดลง แสดงว่าคุณเจอต้นตอของปัญหาแล้ว

วิธีแก้ไขอย่างถูกต้อง:

  • ใช้ worker_threads สำหรับงาน crypto หนักๆ อย่าง bcrypt เพื่อไม่ให้ไปรบกวน libuv pool
  • ใช้ dns.resolve แทน dns.lookup เพราะเป็น async resolver ที่แท้จริง
  • ใช้ streams สำหรับงาน zlib เพื่อคืน slot ให้เร็วขึ้น
  • หลีกเลี่ยงการทำงานกับ filesystem หนักๆ ในเส้นทางหลัก (main request paths) ของการรับ request

เลิกจ้องมองแดชบอร์ดที่เป็นสีเขียว ในขณะที่ผู้ใช้งานของคุณกำลังรอคอย

Source: https://dev.to/r9v/the-nodejs-bug-thats-invisible-to-your-monitoring-oo8