ได้โปรด Log เถิด

เรื่อง Log ที่แสนจะธรรมดา

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

ในทาง Computer จะมีสิ่งหนึ่งที่เรียกว่า Log ซึ่งคือไฟล์หรือ Database หรืออะไรก็แล้วแต่ที่เก็บข้อมูลที่บอกว่าในเวลานั้นเกิดอะไรขึ้นบ้าง สำหรับผมคงคล้ายๆไดอารี่เขียนบันทึกชีวิตประจำวันว่าทำอะไรไปบ้าง โดยตัว Log คนนั้นส่วนใหญ่จะมองเป็นของไร้ค่าเมื่อทุกอย่างทำงานเป็นไปได้ดี ราบลื่น ไม่มีอะไรสะดุด แต่เมื่อใดก็ตามที่เกิดปัญหาขึ้นมา Log จะมีค่าขึ้นมาทันที คงคล้ายๆกับประกันภัยรถยนต์ที่คนบ่นว่าทำไปทำไมก็ไม่ชน แต่เมื่อไหร่ก็ถามที่มีการชนมันจะช่วยเหลือคุณได้ มาถึงจุดนี้คงมีคำถามว่าทำไมผมถึงหัวร้อนก็ไม่มีอะไรมากไปกว่า ไม่มีการเขียน Log ไว้โว้ยยยยยยยยยยย

ส่วนต่อไปจะเป็นส่วนที่เขียนความรู้เกี่ยวกับ Log ที่ผมเคยอ่านหรือได้มาจากตอนทำงาน

  • Log มีคนเเขียนไว้แล้วไม่ต้อง Implement ใช้เอง

ตอนเรียนจบใหม่ไฟแรงมาใหม่มีอะไรก็อยากเขียนเองไปหมดไม่รวมแม้แต่ Log แต่พอเขียนๆไปก็จะรู้ว่า เฮ้ย มันมีปัญหา มันไม่สมบูรณ์ มีมีบัค ประเด็นมันอยู่ที่ Log เป็นงานรองไม่ใช่งานหลัก มันเป็นงานที่ “ควรทำ” ไม่ใช่สิ่งที่ “ต้องทำ” เหมือนกับ Feature หลักที่ต้องทำส่งลูกค้า ดังนั้นเราไม่เควรทำ Log ขึ้นมาใช้เองถ้าไม่จำเป็น ครับผมบอกว่าถ้าไม่จำเป็นแต่บางครั้งเราอาจต้องสร้าง Log ขึ้นมาเองก้ได้เพราะเหตุผลบางประการ

งั้นก็โคตรสิ้นหวังเลยสิเขียน Log ไม่ได้เพราะไม่ใช่งานหลัก แต่โลก Programmer ไม่สิ้นคนดี ในหลายๆภาษาเป็นที่นิยมในปัจจุบันจะมีเหล่ากลุ่ม Programmer คนดีช่วยกันพัฒนา Lib Log ชั้นดีขึ้นมา ตัวอย่างเช่น Apache Log4j ที่เขาทำการสร้าง lib Log ของภาษา Java ขึ้นมาและถูกใช้งานอย่างแพร่หลาย เนื่องจากเรียกใช้งานง่ายอีกทั้งยังสามารถต่อเติม Feature ของ Log ให้อีกมากมาย ซึ่งการที่มันถูกใช้อย่างแพร่หลายมันเลยเป็นมาตรฐานแบบกลายๆ (ภาษาฝรั่งเรียกดีแฟคโต้ไรสักอย่างจำไม่ได้แล้ว) เมื่อเราใช้ lib เขา เราก็เหมือนว่าอยู่ในมาตรฐานระดับนึง (มั้งนะ) ดังนั้นก่อนจะเขียน code ภาษาอะไรลองไปค้นหาดูว่ามี lib log ตัวไหนอยู่บ้าง ไม่ต้องสร้างเองนะ

  • Log ให้อ่านรู้เรื่อง

ปัญหาหนึ่งตอนผมเริ่มเขียนใหม่ๆคือเขียน Log ชุ่ยๆ หรือว่าง่ายๆก็ตามตัวอย่าง

1
2
3
[2017-12-13 21:45:38.660] [INFO] app -Add data
[2017-12-13 21:45:39.660] [INFO] app -Add data
[2017-12-13 21:45:40.660] [INFO] app -Add data

มันแปลว่าอะไรไม่เข้าใจขนาด Programmer มาอ่านด้วยกันยังไม่เข้าใจเลยว่ามันแปลว่าอะไรดังนั้นควรเขียนหน่อยว่าทำอะไรอยู่โว้ยยยยย เช่น

1
2
3
[2017-12-13 21:45:38.660] [INFO] app -Add document ref : 32102 to Database complete
[2017-12-13 21:45:39.660] [INFO] app -Add document ref : 32103 to Database complete
[2017-12-13 21:45:40.660] [INFO] app -Add document ref : 32104 to Database complete

อย่างนี้ค่อยพอเข้าใจหน่อยว่าเออกำลังทำอะไรอยู่

  • Log ข้อมูลที่พร้อมในการค้นหา

ตอนแรกที่ผมเริ่มทำงานใหม่ทำถึงไอข้อก่อนหน้านี้ก็โอเคแล้วนะ แต่พอมาเจองานที่ต้องไล่ล่าหาต้นเหตุว่าเกิดจากอะไรแค่ข้อมูลข้างบนมันยังไม่พอ โดยงานส่วนใหญ่ที่ผมเจอจะเป็นงานที่ต้องยุ่งกับ User และ step แบบขั้นตอน มันจะมีพวกคำถามแบบใครคนทำ ทำมาจากที่ไหน คือถ้าเป็น Log ดีๆหน่อยจะบอกชื่อไฟล์ว่ามันสั่งทำงานจาก file ไหน แต่ถ้า Log ไม่ค่อยดีจะไม่บอก พอไม่บอกเราก็จะหาจุดเริ่มต้นที่ควรไปดู source code ได้ โดย หลังจากไล่หาอ่านเรื่องเกี่ยวกับ Best practice เกี่ยวกับ Log ก็เจอเรื่องที่เขาสอนที่ตรงกับงานคือการเขียน log ให้ grep ได้

1
2
[2017-12-02 13:36:58.640] [INFO] e_payment - uid { 1 }  payment_id { 01234567 }  ref1 { 000443 } ref2 { 1 } ref3 { 2017-12-02000001 } : Send request to pay
[2017-12-02 13:37:01.640] [INFO] e_payment - uid { 1 } payment_id { 01234567 } ref1 { 000443 } ref2 { 1 } ref3 { 2017-12-02000001 } : Problem with payment

การทำแบบนี้จะช่วยเราในการระบุข้อมูลเกี่ยวกับ Log ได้ดีขึ้นเพราะเราสามารถ grep ได้ง่าย เช่น ลูกค้ามีปัญหาที่เลข ref1 ซึ่งเป็นเลขที่มนุษย์อ่านออกเราก็สามารถ grep หาว่ามันเกิดอะไรขึ้นบ้าง หรือ ใน error เดียวกัน ฝ่ายเทคจิคแจ้งเกิดปัญหาเราก็สามารถใช้ payment_id ในการค้นหาได้ และสามารถบอกได้ว่าใครเป็นเข้ามาทำ เจ๋งไหม แต่คำเตือนคือ พยายามใส่เฉพาะข้อมูลที่จำเป็น อย่างผมจะเน้นหลักการอะไรที่เป็นตัวอ้างอิงถึงการกระทำนี้ได้ หรือ อ้างอิงถึงสิ่งที่เรากำลังยุ่งอยู่ด้วยได้ผมจะเอามาใส่เช่นตัวอย่าง ผมเอา ref และ payment_id มาใส่ใน log ด้วยเพราะมันใช้อ้างถึงการจ่ายเงินครั้งนี้ได้

  • Log ที่ดีไม่ควรมีงานมาถึง Programmer

ผมเขียนมาถึงไอข้อบนๆเนี่ยก็ดีใจเยอะละนะว่าเขียนได้ดีเลย แต่พองานจริงเข้ามาอีกนิด คือถ้ามี Case (เรียกเหมือนหมอเลย) เกิดขึ้นบ่อยๆเป็ฯเรื่องซ้ำๆบ่อยๆก็จะเริ่มเบื่อ ดังนั้นเราควรทำ Log ที่สามารถดูได้ผ่านตัวผู้ดูแลระบบ หรือ ผ่านตัว User เอง ซึ่งจริงๆคนปกติมนุษย์ทั่วไปเขาจะเรียกกันว่า History ล่ะมั้งขึ้นมา ไอตัว History นี้ควรจะทำขึ้นมาให้ใช้กับงานที่เราคิดว่าต้องการ Tracking มันจริงจังเลยว่าใครเข้ามาทำอะไรกับมันบ้าง หรืองานที่มีผลกระทบเวลาข้อมูลถูกแก้ไข พอเราทำไอตัวนี้ขึ้นมาลูกค้าก็สามารถตรวจสอบได้ว่าไอตัวนี้เกิดปัญหาอะไรขึ้นเองได้ หรือถ้าเขายังโทรมาอีกก็บอกเขาไปว่า

  • Log ตอนไหนและที่ไหนบ้าง

    อันนี้ผมแนะนำถึงอะไรที่เราควร Log ตอนไหนและที่ไหน

    1. ตรง Controlflow ของส่วนที่ติดต่อกับผู้ใช้ หรือง่ายๆตรงไฟล์ Controller ของ Web นั่นแหละ โดยที่เรา Log ตรงนี้ก็เพราะเราต้องการทราบว่าผู้ใช้มาทำอะไรกับระบบเราบ้าง เวลาเกิดปัญหาจะได้รู้ว่าใครเข้ามาทำอะไรผ่านตัว controller นี้
    2. ตรงไหนก็ตามที่ทำงานแบบ Background เพราะเราไม่มีคนมานั่งเฝ้าตอนมันทำงานเวลาเกิดปัญหาก็จะมีแต่ Log นั่่นแหละที่บอกว่ามันทำอะไรไปบ้าง
    3. ตรงส่วนที่มีการรับส่งข้อมูลระหว่างระบบเพราะเราจะได้ใช้ดูว่า เราส่งอะไรไปใช้เขา และ เขาตอบกลับอะไรกลับมา อันนี้ควรทำเป็นอย่างยิ่งเพราะมันมักจะมีปัญหาโต้เถียงกันบ่อยเพราะแต่ละคิดว่าตัวเองไม่ผิด อีกทั้งอาจจะต้องรอการติดต่อจากอีกฝ่าย เคยรอการตอบกลับจากหน่วยงานรัฐ ถาม 10 โมงตอบ 10 โมงอีกวันก็มี ดังนั้นมี Log ส่งให้เขาดูก็จะดีกว่าให้เขาไปหาเองเป็นการช่วยลดเวลาการทำงานของเราด้วย

ตัดจบดีกว่า

สุดท้ายผมขอตัดจบละกันเพราะมันจะยืดยาวจนเกินไป จริงๆมีอีกหลายเรื่องที่อยากเขียนคุยเช่น Level log, ขนาด log , log หลาย line แต่พอมาคิดดูอีกที มันก็มีข้อมูลของต่างประเทศเยอะแยะให้อ่านแถมน่าเชื่อถือกว่าด้วยเลยไม่เขียนดีกว่า

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

Ref :
https://www.codeproject.com/Articles/42354/The-Art-of-Logging