RAC รับ Transaction พอๆ กัน แต่ COMMIT ช้าต่างกัน 2.5 เท่า

เรื่องราวของเหตุการณ์ · Case Story

จำนวน Transaction ใกล้เคียงกัน แต่เวลาที่ใช้ยืนยันรายการกลับต่างกันมาก

ระบบนี้ใช้ Oracle RAC (ฐานข้อมูลเดียวที่มีหลาย Instance ช่วยกันให้บริการ) ทีมเก็บ AWR ของทั้งสอง Instance ในช่วงเวลาเดียวกันประมาณ 60 นาที สิ่งแรกที่เห็นคือทั้งสองฝั่งรับ Transaction แทบเท่ากัน: Instance 1 ประมาณ 71.13 ครั้งต่อวินาที และ Instance 2 ประมาณ 70.64 ครั้งต่อวินาที

แต่เมื่อดูเวลาที่ Oracle ใช้ยืนยันแต่ละ Transaction ภาพกลับต่างกันชัดเจน Instance 1 รอ log file sync เฉลี่ย 10 มิลลิวินาที ขณะที่ Instance 2 รอเฉลี่ยเพียง 4 มิลลิวินาที ทั้งที่จำนวน Wait ประมาณ 251,893 กับ 249,981 ครั้ง และ Waits ต่อ Transaction เท่ากันที่ประมาณ 0.99

Application ส่ง COMMIT → LGWR เขียน Redo → Oracle ยืนยัน Transaction

Redo คือสมุดบันทึกการเปลี่ยนแปลงที่ Oracle ใช้กู้ข้อมูลเมื่อระบบขัดข้อง ส่วน LGWR หรือ Log Writer คือ Process ที่นำ Redo ไปเก็บใน Online Redo Log

ช่วงตั้งแต่งานส่ง COMMIT (คำสั่งยืนยันรายการ) จน Oracle ตอบกลับ จะปรากฏเป็น Wait Event ชื่อ log file sync หากเวลานี้สูง งานที่ต้องยืนยัน Transaction บ่อยจะเสียเวลารอตรงจุดเดิมซ้ำ ๆ

10ms Instance 1 · log file sync 2,420 วินาทีรวม · 38.3% ของ DB Time

4ms Instance 2 · log file sync 920 วินาทีรวม · 25.7% ของ DB Time

3,791 Instance 1 · Redo bytes/Transaction Redo rate ประมาณ 269,682 bytes/second

1,501 Instance 2 · Redo bytes/Transaction Redo rate ประมาณ 106,010 bytes/second

AWR จึงบอกเราได้สองเรื่องที่เกิดพร้อมกัน: Instance 1 สร้าง Redo ต่อ Transaction มากกว่า Instance 2 ประมาณ 2.5 เท่า และรอการยืนยัน COMMIT นานกว่าประมาณ 2.5 เท่า ตัวเลขนี้ยังไม่พิสูจน์ว่า Redo ที่มากกว่าเป็นสาเหตุเพียงอย่างเดียว แต่ชัดพอที่จะเปลี่ยนคำถามจาก “ระบบกระจายงานเท่ากันหรือไม่” เป็น “เหตุใด Commit path ของ Instance 1 จึงใช้เวลามากกว่า”

จุดที่เปลี่ยนทิศทางการวิเคราะห์ จำนวน Transaction และ COMMIT ไม่ได้เอียงไปฝั่งใดอย่างมีนัยสำคัญ ทีมจึงไม่เริ่มจากการปรับ Connection หรือ Load Balancing แต่ตามรอยตั้งแต่ขนาด Redo ต่อ Transaction, LGWR, CPU scheduling, Redo write และงาน Backup ที่เกิดในช่วงเดียวกัน

อยากเข้าใจศัพท์ให้ลึกขึ้น?

อ่านต่อได้ที่ log file sync คืออะไร, RAC ช่วยให้เห็นความต่างอย่างไร และ ตัวเลขจาก AWR

เส้นทางการวิเคราะห์ · The Investigation

จากความต่าง 10ms กับ 4ms ไปหาว่าเวลาเสียอยู่ตรงไหน

บทที่ 1 · เทียบงานก่อนเทียบเวลา

สอง Instance รับ Transaction และ COMMIT ใกล้เคียงกัน

Transaction rate ต่างกันไม่ถึง 1% จำนวน log file sync ต่างกันประมาณ 0.8% และ Waits ต่อ Transaction เท่ากัน การกระจายจำนวนงานจึงไม่ใช่คำอธิบายหลักของช่องว่าง 10ms กับ 4ms RAC มีประโยชน์ตรงนี้ เพราะทำให้ทีมเปรียบเทียบสอง Instance ของระบบเดียวกันในช่วงเวลาเดียวกันได้

บทที่ 2 · ดูน้ำหนักของแต่ละ Transaction

จำนวนใกล้กัน แต่ Instance 1 สร้าง Redo มากกว่า

Instance 1 สร้าง Redo ประมาณ 3,791 bytes ต่อ Transaction ขณะที่ Instance 2 อยู่ที่ประมาณ 1,501 bytes จึงเห็นว่างานหนึ่ง Transaction ของสองฝั่งมีปริมาณการเปลี่ยนแปลงไม่เท่ากัน ทีมต้องตามต่อว่าความต่างมาจากรูปแบบงานใด และสัมพันธ์กับ Commit latency มากเพียงใด ไม่ใช้จำนวน Connection หรือ Transaction เพียงค่าเดียวแทนภาระจริง

บทที่ 3 · แยก Redo write ออกจากเวลาที่ Session รอ

`log file parallel write` เฉลี่ยใกล้กัน จึงยังโทษ Disk ไม่ได้

log file parallel write (เวลาฝั่ง LGWR ขณะเขียน Redo) เฉลี่ยประมาณ 1ms ทั้งสอง Instance แต่ log file sync ต่างกัน 10ms กับ 4ms แสดงว่าเวลาที่ Session รอครอบคลุมมากกว่าการเขียน Disk ทีมจึงตรวจทั้งปริมาณ Redo, การได้ใช้ CPU ของ LGWR, การรวมคำขอ COMMIT, การแจ้งผลกลับไปยัง Session และ Timeline ของ Backup ที่ปรากฏเด่นบน Instance 1

หลังดำเนินการ: ทีมปรับจุดที่เกี่ยวข้องกับ Commit Frequency, LGWR, Storage และ Job Timeline แยกต่อ Instance ทำให้ Transaction ตอบสนองดีขึ้นและ Oracle RAC ทำงานเสถียรขึ้น

เบื้องหลังการแก้ · What We Did

เปลี่ยนตัวเลขใน AWR ให้เป็นจุดตรวจที่ลงมือแก้ได้

ทีมใช้ RAC เป็นข้อมูลเปรียบเทียบ แล้วไล่ตรวจ Commit path แทนการเดาว่าต้องเปลี่ยน Storage หรือขยาย Redo Log ทันที:

ยืนยันก่อนว่าระยะเวลา AWR, Transaction rate, จำนวน COMMIT และ Waits ต่อ Transaction ของสอง Instance เปรียบเทียบกันได้
เทียบ Redo size ต่อวินาทีและต่อ Transaction เพื่อเห็นว่าจำนวนงานใกล้กัน แต่ปริมาณการเปลี่ยนแปลงต่างกัน
เปรียบเทียบ log file sync ทั้ง Total wait, Average wait และ Wait histogram แยกตาม Instance
ตรวจ log file parallel write เพื่อแยกเวลาฝั่ง LGWR เขียน Redo ออกจากเวลาที่ Foreground Session รอทั้งหมด
ตรวจ CPU scheduling และ I/O latency ที่สัมพันธ์กับ LGWR โดยใช้ Timeline เดียวกับช่วงที่ผู้ใช้มีอาการ
เทียบ Backup timeline และ Global Cache waits โดยไม่รวมทุก Wait ที่เกิดพร้อมกันเป็นสาเหตุเดียว
ปรับจุดที่เกี่ยวข้องแยกต่อ Instance และติดตามการตอบสนองของ Transaction หลังเปลี่ยนแปลง

หลักสำคัญ: log file sync บอกว่าผู้ใช้กำลังรอการยืนยัน COMMIT แต่การเลือกวิธีแก้ต้องตามต่อให้ครบว่าเวลาอยู่ที่ Application, LGWR, CPU, Storage หรือภาระอื่นที่ชนกันในช่วงนั้น

ห้องเทคนิค · For DBA/IT

เปิดดูความหมายของ Wait Event และตัวเลข AWR

เนื้อหาส่วนนี้เก็บศัพท์และตัวเลข Oracle ไว้ครบสำหรับ DBA/IT และการค้นหา แต่พับไว้เพื่อให้เรื่องหลักอ่านต่อเนื่อง

log file sync คืออะไร และเกี่ยวกับ COMMIT อย่างไร

เมื่อ Foreground Session ทำ COMMIT หรือ ROLLBACK, LGWR ต้องเขียน Redo ที่จำเป็นลง Online Redo Log หลังจาก LGWR เขียนเสร็จและแจ้งกลับ Session จึงทำงานต่อได้ เวลาที่ Foreground Session รอวงจรนี้ ปรากฏเป็น Wait Event log file sync

Event นี้จึงครอบคลุมมากกว่าความเร็วของ Disk เพียงจุดเดียว เพราะเส้นทางยังเกี่ยวข้องกับ การส่งคำขอจาก Session, การได้ใช้ CPU ของ LGWR, การเขียน Redo และการ Post กลับไปยัง Session

ทำไม Oracle RAC ต้องวิเคราะห์แยกแต่ละ Instance

Oracle RAC (Real Application Clusters) เปิดให้หลาย Instance เข้าถึงฐานข้อมูลเดียวกัน แต่ละ Instance มี Foreground Session, Background Process, LGWR และ Redo thread ของตัวเอง จึงมี Commit rate, CPU scheduling และ Wait profile ต่างกันได้ แม้จะอยู่ในช่วงเวลาเดียวกัน

การเห็น Instance 1 รอเฉลี่ย 10ms ขณะที่ Instance 2 รอเฉลี่ย 4ms ช่วยกำหนดขอบเขตการตรวจได้ดีกว่าการใช้ค่าเฉลี่ยรวมทั้ง Cluster เมื่อ Transaction rate และจำนวน Commit ใกล้เคียงกัน RAC จึงทำหน้าที่เหมือนข้อมูลเปรียบเทียบว่า เหตุใด Commit path ของ Instance 1 จึงใช้เวลามากกว่า

หลักฐานจาก AWR ของ Oracle RAC ทั้งสอง Instance

AWR (Automatic Workload Repository) เป็นรายงานสถิติ Performance ของ Oracle ตามช่วงเวลา Case นี้เปรียบเทียบรายงานช่วงเดียวกันประมาณ 60 นาทีของทั้งสอง Instance

AWR Event	Instance 1	Instance 2	อ่านค่าอย่างไร
`log file sync`	251,893 waits 2,420s total Average 10ms 38.3% of DB Time	249,981 waits 920s total Average 4ms 25.7% of DB Time	จำนวน Wait ใกล้กัน แต่ Instance 1 ใช้เวลารวมและเฉลี่ยมากกว่า
Transactions/second	71.13	70.64	จำนวน Transaction ใกล้เคียงกันมาก
Redo bytes/second	269,681.82	106,009.55	Instance 1 สร้าง Redo rate มากกว่าประมาณ 2.5 เท่า
Redo bytes/Transaction	3,791.22	1,500.61	Transaction ของสองฝั่งมีปริมาณการเปลี่ยนแปลงไม่เท่ากัน
`log file parallel write`	243,784 waits 338s total Average 1ms	246,992 waits 190s total Average 1ms	ค่าเฉลี่ยฝั่ง LGWR write ใกล้กัน จึงไม่ควรสรุปว่า Disk เป็นคำตอบทั้งหมด
`Backup: sbtbackup`	17.3% 5 waits	—	เป็น Administrative wait; อ่านร่วมกับจำนวน Wait และ Backup timeline
`Backup: sbtwrite2`	12.9%	—	แยกตรวจเส้นทาง Backup และ Media Manager
`gc current block 2-way`	12.2%	18.1%	Global Cache wait ของ RAC; ไม่ใช่ Commit wait โดยตรง

log file parallel write, Commit rate และ Wait histogram ช่วยอะไร

log file parallel write เป็น Wait Event ฝั่ง LGWR ระหว่างเขียน Redo ไปยัง Online Redo Log การเทียบกับ log file sync ช่วยดูว่าเวลาที่ Foreground Session รอสัมพันธ์กับเวลาเขียนของ LGWR เพียงใด

ใน Case นี้ log file parallel write เฉลี่ยประมาณ 1ms ทั้งสอง Instance ขณะที่ log file sync เฉลี่ย 10ms กับ 4ms ช่องว่างจึงอาจอยู่ในส่วนอื่นของ Commit path เช่น LGWR scheduling, การรวมคำขอ COMMIT หรือการ Post กลับไปยัง Foreground Session

Commit rate บอกจำนวนครั้งที่ Application ขอให้ Oracle ยืนยัน Transaction ส่วน Wait histogram แสดงการกระจายของเวลารอ ช่วยแยกอาการที่ช้าสม่ำเสมอ ออกจากอาการกระตุกเป็นบางช่วง ค่า Average เพียงค่าเดียวอาจซ่อนความต่างนี้

Backup waits และ gc current block 2-way ควรอ่านอย่างไร

Backup: sbtbackup และ Backup: sbtwrite2 เกี่ยวข้องกับงาน Backup ผ่าน SBT/Media Manager โดย Instance 1 มี Backup: sbtbackup เพียง 5 waits จึงต้องอ่านจำนวนครั้งและ Timeline ร่วมกับค่า Average ไม่ใช้ค่าเฉลี่ยสูงเพียงตัวเดียวแทนเวลาตอบสนองของผู้ใช้

gc current block 2-way เกี่ยวข้องกับการส่ง Current Block ระหว่าง RAC Instance เป็นอีกเส้นทางหนึ่งของระบบ จึงแยกวิเคราะห์จาก Commit path แล้วจึงดูว่ามีช่วงเวลาที่สัมพันธ์กันหรือไม่

สิ่งที่ไม่ควรปรับจากชื่อ Wait Event เพียงอย่างเดียว

การเพิ่มขนาด Redo Log มีผลหลักกับความถี่ของ Log Switch ไม่ได้แก้ทุกสาเหตุของ Commit latency และการย้าย Storage ควรทำเมื่อข้อมูล I/O ชี้ว่าเป็นคอขวดจริง

การใช้ Asynchronous Commit อาจเปลี่ยนเงื่อนไขด้าน Durability จึงต้องผ่านการประเมินความเสี่ยงและการอนุมัติของเจ้าของระบบ ไม่ควรใช้เป็นทางลัดเพื่อลด log file sync

แหล่งข้อมูล · Sources

ที่มาของตัวเลขและคำอธิบาย Wait Event

หลักฐาน Case: AWR ของ Oracle RAC สอง Instance และ Fact Sheet ที่จัดทำจากเอกสารต้นทางภายใน โดยไม่เผยแพร่ชื่อไฟล์หรือชื่อระบบ
การปกปิดข้อมูล: ไม่เผยแพร่ชื่อองค์กร ระบบ Hostname, Schema, SQL, Procedure หรือข้อมูลภายในของลูกค้า
Redo และ Redo thread: อ้างอิง Oracle Database Administrator’s Guide: Managing the Redo Log
คำอธิบาย Wait Event: อ้างอิงความหมายทั่วไปจาก Oracle Database Reference

RAC สอง Instance มี Performance Profile ต่างกัน ทั้งที่รับ Transaction ใกล้เคียงกันหรือไม่?

log file sync บอกตำแหน่งที่ Transaction กำลังรอ ทีม VT Technology ช่วยตามเส้นทางตั้งแต่ Application, LGWR และ Redo Log ไปจนถึง CPU, Storage และ RAC แต่ละ Instance เพื่อแก้ให้ตรงจุด

ปรึกษาการวิเคราะห์ Oracle Performance

Oracle RAC รับ Transaction พอ ๆ กัน แต่ทำไมฝั่งหนึ่งรอ COMMIT นานกว่า 2.5 เท่า?