การดีบั๊กกระบวนการ busy

บางครั้งเมื่อเราใช้คำสั่ง php start.php status เราจะเห็นว่ามีกระบวนการที่อยู่ในสถานะ busy ซึ่งหมายความว่ากระบวนการนั้นกำลังประมวลผลธุรกิจ โดยปกติแล้วเมื่อประมวลผลเสร็จ กระบวนการที่เกี่ยวข้องจะกลับสู่สถานะ idle ซึ่งในกรณีปกตินั้นจะไม่มีปัญหาอะไร แต่ถ้ากระบวนการนั้นยังคงเป็นสถานะ busy โดยไม่กลับไปเป็น idle แสดงว่าธุรกิจภายในกระบวนการมีการบล็อกหรือวนลูปไม่รู้จบ เราสามารถใช้วิธีการดังต่อไปนี้ในการหาตำแหน่งของปัญหา

การใช้คำสั่ง strace+lsof ในการระบุปัญหา

1、ค้นหา pid ของกระบวนการ busy ในสถานะ
เมื่อรัน php start.php status จะแสดงดังนี้

ในภาพ กระบวนการที่เป็น busy มี pid คือ 11725 และ 11748

2、ติดตามกระบวนการด้วย strace
เลือกกระบวนการหนึ่งที่มี pid (ที่นี่เลือก 11725) รัน strace -ttp 11725 จะแสดงดังนี้

สามารถเห็นว่ากระบวนการกำลังวนลูปการเรียกใช้ระบบ poll([{fd=16, events=.... ซึ่งกำลังรอเหตุการณ์ที่ไฟล์ descriptor fd=16 สามารถอ่านได้ นั่นคือกำลังรอให้ descriptor นี้คืนค่าข้อมูล

ถ้าไม่มีระบบการเรียกใช้ใด ๆ แสดงว่าต้องเก็บเทอร์มินัลปัจจุบันไว้ แล้วเปิดเทอร์มินัลใหม่ รัน kill -SIGALRM 11725 (ส่งสัญญาณเตือนให้กับกระบวนการ) จากนั้นตรวจสอบว่าเทอร์มินัลที่แสดงผล strace มีการตอบสนองหรือไม่ว่ายังติดบล็อกอยู่ที่การเรียกใช้ระบบใดอยู่ หากยังไม่มีการแสดงผลการเรียกใช้ระบบใด ๆ แสดงว่าโปรแกรมน่าจะอยู่ในลูปธุรกิจที่ตายตัว อ้างอิงจากส่วนล่างของหน้า ซึ่งมีสาเหตุอื่น ๆ ที่ทำให้กระบวนการอยู่ในสถานะ busy นาน.

ถ้าระบบติดบล็อกที่การเรียกใช้ระบบ epoll_wait หรือ select นั่นคือสถานะปกติ ซึ่งหมายความว่ากระบวนการอยู่ในสถานะ idle

3、ใช้ lsof เพื่อตรวจสอบไฟล์ descriptor ของกระบวนการ
รัน lsof -nPp 11725 จะแสดงดังนี้

ไฟล์ descriptor 16 ตรงกับบันทึก 16u (ในบรรทัดสุดท้าย) สามารถดูได้ว่า fd=16 เป็นการเชื่อมต่อ tcp และที่อยู่ระยะไกลคือ 101.37.136.135:80 ซึ่งหมายความว่ากระบวนการนั้นกำลังเข้าถึงทรัพยากร http การวนลูป poll([{fd=16, events=.... จึงรอให้เซิร์ฟเวอร์ http ส่งคืนข้อมูล อธิบายว่าทำไมกระบวนการอยู่ในสถานะ busy

การแก้ไข:
เมื่อเราทราบว่ากระบวนการติดบล็อกอยู่ที่ไหน ก็จะง่ายต่อการแก้ไข โดยในกรณีข้างต้นการตรวจสอบพบว่าธุรกิจกำลังเรียกใช้ curl และ url ที่เกี่ยวข้องไม่ได้คืนค่าข้อมูลเป็นระยะเวลานาน ทำให้กระบวนการรอคอยต่อไป ในกรณีนี้สามารถติดต่อผู้ให้บริการ url เพื่อตรวจสอบสาเหตุที่ url ตอบสนองช้า และควรกำหนดค่า timeout ขณะเรียก curl เช่น หากไม่มีการตอบสนองภายใน 2 วินาทีให้เกิด timeout เพื่อหลีกเลี่ยงการบล็อกนานเกินไป (กระบวนการอาจอยู่ในสถานะ busy เป็นเวลาประมาณ 2 วินาที)

สาเหตุอื่น ๆ ที่ทำให้กระบวนการอยู่ในสถานะ busy นาน

นอกจากการติดบล็อกของกระบวนการที่ทำให้เกิดสถานะ busy ยังมีสาเหตุอื่น ๆ ที่อาจทำให้กระบวนการอยู่ในสถานะ busy ดังนี้

1、ธุรกิจมีข้อผิดพลาดร้ายแรงทำให้กระบวนการออกไปเรื่อย ๆ
ปรากฏการณ์： ในกรณีนี้เราจะเห็นว่าการโหลดของระบบค่อนข้างสูง โดย load average ใน status อยู่ที่ 1 หรือสูงกว่า เราจะเห็นตัวเลข exit_count ของกระบวนการสูงมากและเพิ่มขึ้นอย่างต่อเนื่อง
การแก้ไข: รันในโหมด debug (php start.php start โดยไม่ต้องเพิ่ม -d) แล้วดูว่ามีข้อผิดพลาดในธุรกิจอย่างไร แค่แก้ไขข้อผิดพลาดนั้นให้เรียบร้อย

2、โค้ดมีลูปไม่มีที่สิ้นสุด
ปรากฏการณ์： ใน top สามารถเห็นกระบวนการ busy ใช้ cpu สูงมาก และคำสั่ง strace -ttp pid ไม่แสดงข้อมูลการเรียกใช้ระบบใด ๆ
การแก้ไข: อ้างอิงบทความของนกแก้วโดยใช้ gdb และรหัส php เพื่อตรวจสอบ สรุปขั้นตอนจะมีดังนี้：
1、ใช้คำสั่ง php -v เพื่อตรวจสอบเวอร์ชัน
2、ดาวน์โหลดซอร์สโค้ด php เวอร์ชันที่เหมาะสม
3、รันคำสั่ง gdb --pid=busy process pid
4、รัน source php source path/.gdbinit，
5、รันคำสั่ง zbacktrace เพื่อพิมพ์ stack trace
ในขั้นตอนสุดท้ายสามารถเห็น stack trace ของรหัส php ที่กำลังทำงานอยู่ ซึ่งเป็นตำแหน่งที่เกิดลูปตายตัว
หมายเหตุ: ถ้า zbacktrace ไม่แสดง stack trace อาจจะหมายความว่าคุณไม่ได้ประกอบ php ด้วยพารามิเตอร์ -g จำเป็นต้องทำการคอมไพล์ใหม่และรีสตาร์ท workerman เพื่อตรวจสอบ

3、เพิ่มตัวจับเวลาไม่มีที่สิ้นสุด
ธุรกิจมีการเพิ่มตัวจับเวลาไม่หยุดแต่ไม่ลบ ทำให้มีตัวจับเวลามากขึ้นเรื่อย ๆ ในการทำงานของกระบวนการ ในที่สุดทำให้กระบวนการทำงานตัวจับเวลาอย่างไม่มีที่สิ้นสุด ตัวอย่างโค้ดด้านล่าง:

$worker = new Worker;
$worker->onConnect = function($con){
    Timer::add(10, function(){});
};
Worker::runAll();

โค้ดด้านบนจะเพิ่มตัวจับเวลาหลังจากที่มีการเชื่อมต่อของไคลเอนต์ แต่ในโค้ดธุรกิจทั้งหมดไม่มีตรรกะในการลบตัวจับเวลา ทำให้กระบวนการมีตัวจับเวลาเพิ่มขึ้นเรื่อย ๆ จนทำให้เกิดสถานะ busy
โค้ดที่ถูกต้อง:

$worker = new Worker;
$worker->onConnect = function($con){
    $con->timer_id = Timer::add(10, function(){});
};
$worker->onClose = function($con){
    Timer::del($con->timer_id);
};
Worker::runAll();