โพสต์มอร์เท็มเหตุขัดข้อง 73 ชั่วโมงของ Roblox เมื่อปีที่แล้ว

สรุปเหตุขัดข้อง

• เหตุขัดข้องกินเวลานาน 72 ชั่วโมง

• สาเหตุรากมี 2 ข้อ

  • เกิดการแย่งทรัพยากรมากเกินไปและประสิทธิภาพลดลง หลังเปิดใช้ฟีเจอร์สตรีมมิงใหม่ของ Consul ในสภาวะที่มีโหลดการอ่าน/เขียนสูงผิดปกติ

  • ในสภาวะโหลดบางแบบ ทำให้เกิดปัญหาด้านประสิทธิภาพใน BoltDB โอเพนซอร์สที่ Consul ใช้จัดการ write-ahead-log สำหรับการเลือกผู้นำและการทำ data replication

• Consul คลัสเตอร์เดียวทำให้ผลกระทบจากปัญหาเหล่านี้รุนแรงขึ้น

• เหตุขัดข้องยืดเยื้อเพราะต้องค้นหา 2 ปัญหานี้ที่ดูเหมือนไม่เกี่ยวกันซึ่งซ่อนอยู่ใน implementation ของ Consul

• ระบบมอนิเตอร์ริงที่ควรช่วยให้เห็นสาเหตุของเหตุขัดข้องได้ชัดเจนกว่านี้ กลับพึ่งพาระบบที่ได้รับผลกระทบแบบเดียวกับ Consul จึงยิ่งทำให้หาสาเหตุได้ยากขึ้น

สภาพแวดล้อมของคลัสเตอร์และ HashiStack

• Roblox ดูแลเซิร์ฟเวอร์ 18,000 เครื่องและคอนเทนเนอร์ 170,000 ตัว

• ใช้ Nomad, Consul และ Vault ซึ่งโดยทั่วไปเรียกรวมกันว่า HashiStack

ตอนนั้น Roblox อัปเกรด Consul จาก 1.9 เป็น 1.10 เพื่อจะใช้ฟีเจอร์สตรีมมิง

การตรวจพบครั้งแรก (10/28 13:37)

วันที่ 18 ตุลาคมช่วงบ่าย ประสิทธิภาพของ Vault ลดลง และภาระ CPU ของเซิร์ฟเวอร์ Consul เครื่องหนึ่งสูงขึ้น

การจำแนกเบื้องต้น (10/28 13:37 – 10/29 02:00)

• latency การเขียนเพิ่มขึ้นในเมตริกของ Consul คลัสเตอร์

• สงสัยว่ามีสาเหตุมาจากฮาร์ดแวร์เสื่อมประสิทธิภาพ และเริ่มเปลี่ยนหนึ่งในโหนดของ Consul คลัสเตอร์

• พนักงานของ HashiCorp เข้าร่วมและเริ่มทำงานร่วมกัน

• แม้เปลี่ยนฮาร์ดแวร์แล้ว ประสิทธิภาพของ Consul ก็ยังคงลดลงต่อเนื่อง และตอน 16:35 จำนวนผู้เล่นลดลงเหลือ 50% ของปกติ

• Consul ถูกใช้เป็น service discovery และทั้ง Nomad กับ Vault ก็พึ่งพา Consul ดังนั้น Consul จึงเป็น SPoF

• ตอนนี้จึงตั้งสมมติฐานใหม่ว่าทราฟฟิกเป็นสาเหตุ โดยคิดว่า Consul ไม่สามารถรับโหลดจากทราฟฟิกสูงได้อีกต่อไป

• เปลี่ยนทุกโหนดของ Consul คลัสเตอร์เป็นระบบที่แรงกว่าเดิม (เพิ่มจำนวนคอร์เป็น 2 เท่า และใช้ NVME SSD ที่เร็วขึ้น)

• การย้าย Consul ใกล้เสร็จแล้ว แต่คลัสเตอร์ก็ยังไม่กลับมาปกติ

ความพยายามกู้คืนบริการ #1 (10/29 02:00 – 04:00)

• ตัดสินใจย้อนกลับไปใช้ snapshot ของ Consul คลัสเตอร์ก่อนเกิดเหตุขัดข้อง

• ข้อมูลผู้ใช้ยังปลอดภัย และแม้ข้อมูลระบบจะสูญหายบางส่วนก็ยอมรับได้

• หลัง restore snapshot ได้บล็อกการเข้าถึงด้วย iptables เพราะกังวลว่าโหลดจากระบบที่สื่อสารกับ Consul ตลอดเวลาจะทำให้เกิดปัญหาอีกหลังการกู้คืน

• หลัง restore snapshot ตัวชี้วัดดูดีขึ้น แต่เมื่อปลดบล็อก iptables ก็กลับเข้าสู่สภาวะขัดข้องเดิมอีกครั้ง

ความพยายามกู้คืนบริการ #2 (10/29 04:00 – 10/30 02:00)

• บล็อกทราฟฟิกภายนอกและตัดการใช้งานที่ไม่จำเป็นออก ทำให้บริการที่เดิมรันอยู่หลายร้อยอินสแตนซ์ลดลงเหลือเลขหลักเดียว

• พยายามกู้คืนบริการอีกครั้ง แต่ Consul ก็กลับเข้าสู่สภาพผิดปกติอีก

• ตระหนักว่านอกจากปัจจัยด้านประสิทธิภาพที่คาดไว้ตอนแรกแล้ว ยังมีอย่างอื่นอีก จึงเริ่มมองเข้าไปข้างใน Consul เอง ไม่ใช่มองจากมุมของ Roblox ต่อ Consul เท่านั้น

การวิเคราะห์การแย่งทรัพยากร (10/30 02:00 – 10/30 12:00)

• หลังวิเคราะห์ต่ออีก 10 ชั่วโมง พบว่าการเขียนของ Consul ถูกบล็อกเป็นเวลานาน

• ยังไม่รู้สาเหตุของการแย่งทรัพยากร แต่ประเมินว่าการเปลี่ยน CPU จาก 64 คอร์เป็น 128 คอร์ตอนแรกยิ่งทำให้การแย่งทรัพยากรรุนแรงขึ้น

• ตัดสินใจกลับไปใช้ 64 คอร์ แต่ก็ไม่ช่วยอะไร

ค้นพบสาเหตุราก (10/30 12:00 – 10/30 20:00)

• ฟีเจอร์สตรีมมิงของ Consul ถูกเปิดใช้มาหลายเดือนแล้ว และกำลังทยอยใช้งานเพิ่ม เพราะมันช่วยลดการใช้ CPU และแบนด์วิดท์เครือข่ายได้

• หนึ่งวันก่อนเกิดเหตุ วันที่ 27 เวลา 14:00 ได้เปิดใช้ฟีเจอร์นี้ในแบ็กเอนด์สำหรับ routing ทราฟฟิก

• เพราะเปิดใช้มาก่อนหนึ่งวันและทำงานได้ดี จึงไม่ได้คิดว่าเป็นสาเหตุ

• หลังวิเคราะห์ประสิทธิภาพ ก็พบหลักฐานว่าโค้ดสตรีมมิงทำให้ CPU สูงขึ้น

• ปิดสตรีมมิงและ deploy เสร็จแล้ว ก็ยืนยันได้ว่า latency ของการเขียน KV ใน Consul ลดลง (ในที่สุด!)

• HashiCorp อธิบายว่าสตรีมมิงมีประสิทธิภาพมากกว่า แต่ implementation ใช้องค์ประกอบควบคุมการทำงานพร้อมกันจำนวนน้อยกว่า (Go channel) แทน long polling -> ภายใต้โหลดสูง สิ่งนี้ทำให้การแย่งทรัพยากรบน Go channel เดียวรุนแรงขึ้นและลดทอนประสิทธิภาพลง

• แม้จะเริ่มเห็นทางออก แต่ก็ยังพบการเลือกผู้นำใหม่เป็นระยะ และผู้นำบางรายยังมีปัญหา latency คล้ายเดิม

• จึงตัดสินใจมุ่งทำให้บริการกลับสู่ภาวะปกติ โดยอาศัยข้อสรุปว่าหากไม่เลือกผู้นำบางตัว คลัสเตอร์จะทำงานได้ปกติ

• หลังจากนั้น HashiCorp จึงสืบหาสาเหตุรากต่อ และพบว่าปัญหาที่ผู้นำบางตัวช้านั้นมาจาก BoltDB

การกู้คืนบริการแคช (10/30 20:00 – 10/31 05:00)

• หลังเหตุขัดข้องผ่านไป 54 ชั่วโมง ก็พร้อมสำหรับการกู้คืนบริการ

• ระหว่างเหตุขัดข้อง ฐานข้อมูลยังปกติ แต่ระบบแคชที่รองรับคำขอ 1 พันล้านครั้งต่อวินาทีอยู่ในสภาพผิดปกติ

• เมื่อกู้คืนแคชนี้และยืนยันว่าเป็นปกติแล้ว เวลาก็ผ่านไป 61 ชั่วโมงนับจากเริ่มเหตุขัดข้อง

การกลับมาของผู้ใช้ (10/31 05:00 – 10/31 16:00)

• เริ่มเตรียมให้บริการกลับมาในวันที่ 31 เวลา 5:00 และเสร็จสิ้นตอน 10:00

• ควบคุมจำนวนผู้เล่นที่เข้าถึงผ่าน DNS โดยเฝ้าดูมอนิเตอร์ริงไปพร้อมกับค่อย ๆ เพิ่มขึ้น

• หลังผ่านไป 73 ชั่วโมง ผู้เล่นทุกคนจึงกลับมาเข้าถึงได้อีกครั้ง

การวิเคราะห์เพิ่มเติมและการเปลี่ยนแปลงหลังเหตุขัดข้อง

• HashiCorp และ Roblox พัฒนากระบวนการ "compression" เพื่อแก้ปัญหาด้านประสิทธิภาพ

• ปรับปรุง telemetry: มีการพึ่งพาแบบวนซ้ำระหว่างระบบ telemetry กับ Consul ทำให้เมื่อ Consul มีปัญหา ข้อมูลก็ไม่เพียงพอ จึงลบการพึ่งพาแบบวนซ้ำเพื่อไม่ให้ระบบ telemetry ต้องพึ่งพาระบบที่มันกำลังมอนิเตอร์อยู่

• ขยาย availability zone และดาต้าเซ็นเตอร์

• จัดระเบียบข้อมูล KV ที่เก็บไว้ใน Consul โดยย้ายหรือกำจัดข้อมูลที่ไม่จำเป็น แม้จะมีสตอเรจอื่นอยู่แล้วก็ตาม

• กำลังทดสอบ Consul เวอร์ชันใหม่ที่เปลี่ยนจาก BoltDB ไปใช้ bbolt ซึ่งเป็นตัวสืบทอดต่อ

• กระบวนการ bootstrap ทำให้การกู้คืนล่าช้า จึงกำลังทำให้เป็นอัตโนมัติและพัฒนาเครื่องมือกับกระบวนการใหม่

[xguru]

ขอบคุณสำหรับคำแปลครับ

เหตุขัดข้องนาน 72 ชั่วโมงในสเกลระดับนั้นน่ากลัวจริง ๆ