สมัยก่อนที่ผมทำงานกับ Oracle Database ถ้าต้องการดู Stat เกี่ยวกับ Database เมื่อไหร่ ก็ใช้ Enterprise Monitor (EM) หรือ gen report AWR ออกมาดูก็ได้  อย่างง่ายดาย หรือถ้า advance ก็สามารถ query stat ได้จาก table v$ ทั้งหลาย แต่ตอนนี้เมื่อต้องทำงานกับ database อย่าง postgresql มันไม่ได้มี stat pack แบบ Oracle แต่ก็ยังพอหาข้อมูลได้จาก pg_stat_* แต่ก็ยังคิดถึง EM ที่สามารถดู Query ของ database ได้แบบ real-time แล้วจะให้ไป query จาก pg_stat_activity งั้นหรือ ก็คิดว่าไม่น่าถูกต้อง ดังนั้น Dtrace เนี่ยแหละ น่าจะเป็นคำตอบ

Dtrace (dtraceponyDynamic Tracing) เป็น Tool ที่ออกแบบมาสำหรับ Performance Analysis มันสามารถ Trace ได้ตั้งแต่ระดับ Kernel ไปจนถึงระดับ User space และมันติดมากับ Solaris, OS X และ FreeBSD โดยอัตโนมัติอีกด้วย ผมเองก็ได้มีโอกาสใช้งาน Dtrace มาสักพักหนึ่งแล้ว แต่ไม่เคยเขียน Script เองเลย เนื่องจากมี DtraceToolkit ช่วยเหลืออยู่ตลอด แต่มาในครั้งนี้ จะพยายามศึกษาและเขียน script ง่ายๆขึ้นมาใช้งานเอง

 *Dtrace Mascot (Dtrace Pony)

การติดตั้ง PostgreSQL 9.4 + Dtrace Support บน FreeBSD 10.1

เนื่องจาก Dtrace ไม่ได้ถูก enable มาโดย default บน package postgresql เราจึงต้องทำการ compile จาก ports แน่นอนว่าการติดตั้งบน freebsd มันไม่ได้ง่ายเท่ากับ Linux ทั้งหลาย แต่ข้อดีของมันคือ Ports มักจะมีการ update อยู่ตลอดเวลา และเราสามารถ install package ใหม่ๆ ได้อย่างไม่ยากเย็น และไม่ต้องยุ่งเรื่อง dependency เสียแค่เวลา compile package เท่านั้นเอง

  1. kldload dtraceall #ทำการ load dtrace ลงใน kernel
  2. echo”dtraceall_load=YES” >> /boot/loader.conf #ให้ทำการ load dtrace ทุกครั้งเมื่อ boot
  3. chmod 0666 /dev/dtrace/helper #แก้ permission ให้ user ของ postgresql สามารถใช้งาน dtrace ได้
  4. echo “perm /dev/dtrace/helper 0666” >> /etc/devfs.conf  #แก้ permission ทุกครั้งเมื่อ boot
  5. portsnap fetch
  6. portsnap extract
  7. cd /usr/ports/databases/postgresql94-server/
  8. make config #แล้วเลือก dtrace ด้วย
  9. make install clean
  10. echo “postgresql_enable=’YES'” >> /etc/rc.conf
  11. /usr/local/etc/rc.d/postgresql initdb
  12. service postgresql start
  13. dtrace -l |grep postgres | wc -l #ต้องแสดงค่ามากกว่า 0

หาก postgresql ไม่สามารถ register probe กับ dtrace ได้ ให้ทำการลอง reboot แล้วเช็ค permission ของ dtrace helper และ ลองโหลด kld ใหม่อีกครั้ง

การเขียน Script Dtrace

การเขียน script dtrace นั้นจะเป็นการเขียนที่ผูกอยู่กับ probe โดย probe คือ code ที่ฝังอยู่ในโปรแกรม probe จะทำงานเมื่อ condition ตรงตามเงื่อนไขที่ได้กำหนดไว้ เช่น หาก query เริ่มต้นทำงาน ให้เรียก query-start และเมื่อ query ทำงานเสร็จ ให้เรียก query-done โดยเราสามารถดูรายชื่อ probe ทั้งหมดได้จาก dtrace -l

นอกจากนี้ probe แต่ละตัวก้ยังมี parameter ของมัน ซึ่งเราสามารถเอาค่าจาก parameter เหล่านั้นมาแสดงผลออกทางหน้าจอได้ โดยเราสามารถดูรายละเอียดของ probe ได้จาก source code สำหรับ kernel แต่ในส่วนของ application นั้น ส่วนใหญ่จะมีคู่มือมาให้ อย่างในส่วนของ postgresql ก็สามรถดูได้จากที่นี่

เนื่องจาก postgresql เป็น multi-process ทำให้ dtrace จะแสดง probe ของแต่ละ process ออกมา การเขียน script ก็ควรจะเขียนให้ครอบคลุมทุกๆ process ด้วย

root@f10:/usr/ports/databases/postgresql94-server # dtrace -l |grep query-start 51355 postgresql882          postgres                      PostgresMain query-start 51430 postgresql884          postgres                      PostgresMain query-start 51505 postgresql885          postgres                      PostgresMain query-start 51580 postgresql886          postgres                      PostgresMain query-start 51655 postgresql887          postgres                      PostgresMain query-start 51730 postgresql888          postgres                      PostgresMain query-start 51955 postgresql939          postgres                      PostgresMain query-start

ตัวอย่างที่ 1 แสดง query String ของ SQL ที่ถูกป้อนเข้ามาใน postgres

 dtrace -n ‘postgresql*:::query-start{ printf(“%s”, copyinstr(arg0)); }’

dtrace -n #บอกให้ทำงานแบบ one-liner

postgresql*:::query-start # สำหรับทุกๆ Probe query-start ที่เกี่ยวข้องกับ provider postgresql (เราใช้ * เพื่อบอกว่าเอาทั้งหมด)

printf(“%s”, copyinstr(arg0)); # print ค่าของ argument 0 ออกมาโดยใช้คำสั่ง copyinstr เราไม่สามารถ print ค่า arg0 ออกมาได้โดยตรงด้วย stringof() ต้องใช้ copyinst() นี้ช่วย ไม่เช่นั้น script จะรันได้ไม่ถูกต้อง เนื่องจากค่าของ arg0 นั้นอยู่ในส่วนของ user space แต่ dtrace ทำงานอยู่บน kernel ทำให้การอ้างอิง address นั้นไม่ตรงกัน – อ้างอิง1

ผลลัพธ์

# dtrace -n ‘postgresql*:::query-start{ printf(“%s”, copyinstr(arg0)); }’

dtrace: description ‘postgresql*:::query-start’ matched 7 probes

dtrace: buffer size lowered to 1m

CPU     ID                    FUNCTION:NAME

0  51955         PostgresMain:query-start select * from pg_stat_activity;

จะเห็นว่าเราสามารถแสดง Query ที่กำลังรันในแบบ real-time ได้แล้ว ทุกๆครั้งที่ postgresql ได้รับคำสั่งให้รัน query ใดๆ ก็จะทำการ trigger probe แล้ว dtrace ของเราก็จะถูกเรียก ให้ทำงานตาม script ที่ได้กำหนดไว้ข้างต้น

ตัวอย่างที่ 2 แสดง query string และ ระยะเวลาที่ใช้ในการทำงาน ในตัวอย่างนี้เราจะใช้ probe สองตัว นั่นก็คือ query-start และ query-done พูดง่ายๆก็คือจับเวลา ระหว่าง การทำงานของ probe สองตัวนี้นั่นเอง

#Probe 1

postgresql*:::query-start{

self->timest = timestamp;

}

#Probe 2

postgresql*:::query-done{

self->timeend = (timestamp-(self->timest));

printf(“%s %d ms”, copyinstr(arg0), self->timeend/1000000);

}

Probe 1 ทำการบันทึกค่า Timestamp ลงใน ตัวแปร  timest แบบ thread local

Probe 2 ทำการบันทึกค่า timestamp – ตัวแปร timest ลงในตัวแปร timeend แล้วทำการ print ออกมาบนหน้าจอ จะเห็นว่าค่าของ timeend นั้นถูกหารด้วย 1 ล้าน หรือ 10^6 ก็เนื่องจาก ค่า timestamp ใน dtrace นั้นมีหน่วยเป็น nanosec นั่นเอง

ผลลัพธ์

root@f10:~ # dtrace -s query.d

dtrace: script ‘query.d’ matched 14 probes dtrace: buffer size lowered to 1m

CPU     ID                    FUNCTION:NAME

1  51942          PostgresMain:query-done select * from pg_stat_activity; 1 ms

1  51942          PostgresMain:query-done select * from pg_stat_activity; 0 ms

0  51942          PostgresMain:query-done select * from pg_stat_activity; 35 ms

1  51942          PostgresMain:query-done select * from pg_stat_activity; 5 ms

0  51942          PostgresMain:query-done select * from pg_stat_activity; 0 ms

เนื่องจากเป็น script หลายบรรทัด จึงทำการ save เก็บไว้ที่ query.d แล้วเรียกใช้งานด้วยคำสั่ง dtrace -s จะเห็นได้ว่า script เราทำงาน และแสดงระยะเวลาในการ query ตามที่ได้เขียนไว้

สรุป

ว่าจะเขียนเกี่ยวกับ Dtrace มานานมากแล้ว (เป็นปี) แต่ก็ยังไม่มีโอกาส เพราะบางทีมันก็ยากเกิน แต่เอาเข้าจริงถ้าตั้งใจมันก็ไม่ยากมากนัก หากเราไม่ได้ไปเขียน script ซับซ้อนอะไร หากใครมีปัญหาในเรื่องของ Performance Dtrace เป็นตัวเลือกที่ดีที่สามารถมาช่วยแก้ปัญหาได้ แต่หากคุณใช้งาน OS อื่นที่ไม่ใช่สามตัวที่กล่าวมาข้างต้นแล้ว ก็จำเป็นต้องใช้ Tools อื่นๆ ถ้าเป็น Linux ก็ลองดู perf event / sysdig น่าจะช่วยแก้ปัญหาได้ไม่มากก็น้อย