ฮาวทู Logging ไลค์อะโปร ใน Python

Arnon Puitrakul -

เวลาเราเขียนโปรแกรมออกมา เราก็คงอยากรู้ว่า โปรแกรมของเรามันทำงานเป็นอย่างไร มันเป็นปกติอย่างที่มันควรจะเป็นหรือไม่อย่างไร หรืออาจะเป็นเมื่อเราเอาโปรแกรมไปใช้จริงแล้ว ถ้ามันเกิดข้อผิดพลาดอะไรขึ้น Log นี่แหละ จะเป็นตัวช่วยเราในการวินิฉัยปัญหาได้อย่างดีเลยเชียว วันนี้เราจะมาสอนการทำ Log ยังไงให้โปรใน Python กัน

วิธีบ้าน ๆ ผมรู้คุณก็ทำ

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

print('I am running')

นอกจากนั้น ถ้าเราอยากให้มันเก็บลงไฟล์อีก เราก็ต้องเขียนตัว File I/O สำหรับการเขียน Log ลงไปในไฟล์ก็อาจจะเป็น

log_file = open('log.log', 'a')

log_file.write('I am running\n')

log_file.close()

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

def log_me (content) :
	print(content)
    
	log_file = open('log.log', 'a')
	log_file.write('I am running\n')
	log_file.close()

เวลาเรียก เราก็แค่เรียก Function log_me เลยก็ง่ายเหมือนกัน แต่แหม่ ถ้าเราจะเขียนเองทุกครั้ง ก็ไม่ไหวเหมือนกันนะ แต่ไม่ต้องกลัว วันนี้เราจะพาทุกคนมาแก้ปัญหานี้แบบ Once and for all กันด้วย Built-in Function ของ Python

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

อีกปัญหาคือ การจัดการ Log ที่เราเห็นกันเยอะ ๆ คือ การใช้พวก Level ในการบอกพวกความรุนแรง พวกนี้จากที่เราทำงานมา เราบอกเลยว่า มันช่วยได้เยอะมาก ๆ โดยเฉพาะการแยกพวก CRITICAL กับ ERROR ออกมาจากพวกที่เหลือ สำหรับการวินิฉัยปัญหาของโปรแกรม และเราอาจจะดูพวก INFO ประกอบ เพื่อให้รู้ว่า โปรแกรมมันเกิดอะไรขึ้นก่อนที่จะเกิดปัญหาได้ (บางทีมันทำหลายอย่าง ทำให้เรา งง ไปหมด) ถ้าเราไม่แยกกัน มันจะแยก Timeline กันปวดหัวไปหมด การแยกบอกเลยว่าช่วยได้เยอะมาก

Logging

Logging เป็น Built-in Package ที่มากับตัว Python ทำให้เรา ทำ Log ได้ง่ายมาก ๆ มากจริง ๆ โดยให้เราเริ่มจากการ Import มันเข้ามาก่อน

import logging

เท่านี้ก็เรียบร้อยแล้ว ถ้าเราใช้จาก Logging Module เลย เราจะสามารถใช้ Default Configuration ได้ ก็คือ เมื่อเราสั่ง Log ออกมา มันก็จะแสดงผลออกมาที่หน้าจอเรา แต่ถ้าเราต้องการ Config มากกว่านั้น เราจำเป็นต้องสร้างมันออกเป็น Object ออกมา โดยใช้ Code ด้านล่างนี้ได้เลย

logger = logging.getLogger('my-app')

และสุดท้าย เราก็สามารถ Log ด้วยการใส่ ข้อความที่เราต้องการไปได้เลย โดยที่ มันจะมีการแบ่ง Level ของการ Log ออกเป็น 5 Level ด้วยกัน ตามความร้ายแรงคือ

  • CRITICAL เรียกได้จาก logger.critical(<content>)
  • ERROR เรียกได้จาก logger.error(<content>)
  • WARNING เรียกได้จาก logger.warning(<content>)
  • INFO เรียกได้จาก logger.info(<content>)
  • DEBUG เรียกได้จาก logger.debug(<content>)

พอเราเรียก มันก็จะออกมาในหน้าจอของเราได้เลย ปัญหาต่อไปคือ ถ้าเราต้องการที่จะให้มันเขียนไปที่ไฟล์ด้วย เราก็สามารถทำได้เช่นกันผ่านสิ่งที่เรียกว่า Handlers

Handlers

Handlers ทำงานตามชื่อเลยคือ ทำหน้าที่ในการ Handle Log ของเรานั่นเอง จริง ๆ แล้ว Default Handlers ที่ใช้สำหรับในการแสดงผลบนหน้าจอมันชื่อ StreamHandler ถ้าเราต้องการที่จะจัดการ Handlers เอง เราก็สามารถทำได้เหมือนกัน เช่น เราบอกว่า เราอยากให้มันเขียน Log ลงไปใน File ด้วย

ตัวอย่างเช่น เราต้องการที่จะให้เขียน Log ลงไปในไฟล์ด้วย  เราต้องใช้ Handlers ที่ทำงานนั้น เราไม่ต้องเขียนเอง เราใช้ FileHandlers โดยมันจะรับ ค่า 4 ค่าเข้ามาคือ

FileHandler(filename, mode='a', encoding=None, delay=False)

ตรงนี้ เราอาจจะไปอ่านใน Document ของ Python สำหรับข้อมูลเพิ่มเติมได้ แต่สิ่งที่เราอยากให้โฟกัส คือ ชื่อไฟล์ อันนี้ตรงตัวเลยคือที่อยู่ของ Log File ที่เราต้องการจะเขียน และ สุดท้ายคือ Delay ที่เราจะต้องใส่ Boolean ลงไปคือ ถ้าค่าเป็น True ตัว Log File มันจะถูกเปิดเมื่อโปรแกรมต้องเขียน Log และ ถ้าเป็น False คือ ไฟล์จะถูกเปิดเมื่อ FileHandler นี้ถูกสร้างขึ้นมา

พอเราได้ Handler แล้วเราก็เอาไปบอก Logger ว่า เรามี Handlers ผ่านคำสั่งที่ชื่อว่า addHandler()

logger = logging.getLogger('my-app')
log.addHandler(logging.StreamHandler())
log.addHandler(logging.FileHandler('my_log.log'))

log.info('I am a log')

จาก Code ด้านบน เราจะเห็นว่า เราทำการเพิ่ม Handler เข้าไป 2 ตัวคือ SteamHandler สำหรับการแสดงผลที่หน้าจอ และ FileHandler สำหรับการอัด Log ใส่ลงไปในไฟล์ที่ชื่อว่า my_log.log

Formatter

อย่างสุดท้ายที่เราคุยกันคือ ถ้าเราต้องการใส่วันที่ หรือต้องการแบ่ง จัดให้มันมีความอ่านง่าย เดิมที เราก็อาจจะเขียน Function เอง ให้มันจัดมาให้ แล้วยัดใส่ Logger ได้เลย แต่แน่นอนว่า เขาทำมาให้เราแล้วคือ Formatter ซึ่งมันอยู่ใน Handler นั่นแปลว่า ถ้าเรามี Handler สำหรับการแสดงออกหน้าจอ กับ ออกเป็นไฟล์ เราสามารถใช้ Formatter แยกกันได้ ตัวอย่างเช่น

s_handler = logging.StreamHandler()
s_handler.setFormatter(logging.Formatter('%(asctime) - %(levelname) | %(message)'))

logger.addHandler(s_handler)
logging.info('Connecting to Database')

ก่อนหน้านี้ หลาย ๆ คนอาจจะสงสัยใช่มั้ยว่า ถ้าเราบอกว่า StreamHandler มันเป็น Default มาให้เราอยู่แล้ว ทำไมเราถึงยังเพิ่มเองได้อยู่ เพราะแบบนี้แหละ คือ เราสามารถที่จะ Format Log ที่ออกบนหน้าจอเราได้ เลยต้องทำออกมาแบบนี้ และกับ Handler อื่น ๆ เราก็สามารถที่จะ Format ได้เหมือนกันเลย

จากตัวอย่างทำให้ Log ออกมาเป็น ตามด้านล่างนี้

2020-06-14 17:49:34,614 - INFO | Connecting to Database

ส่วนพวก asctime, levelname และ message ที่เราเขียนลงไปก็คือ พวก วันที่ และ Info ตรงที่เราเห็นจากใน Log แนะนำให้ไปดูใน Document ได้เลย มันจะมีพวกรายละเอียดอยู่ว่าเราสามารถเขียนอะไรออกมาได้บ้าง

Filter

สุดท้าย สิ่งที่มันมีมาให้เราอีกอย่างคือ Filter ทำหน้าที่ตามชื่อของมันเลยคือ การเลือกอะไรบางอย่างเข้าไปใน Log ของเราได้ ตัวอย่างเช่น เราอาจจะมีหลาย Handle อาจจะ Log ออกที่หน้าจอด้วย กับมีการ Log ลงไฟล์ด้วย บางที เราอาจจะอยากที่จะแยก Log ในไฟล์บางอย่างออกจากกัน อาจจะเป็น เอาพวก Log ระดับ Crtical แยกออกมาเลย สำหรับการวินิฉัยปัญหาที่รุนแรงโดยเฉพาะ

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

สรุป : Log เถอะ ชีวิตดีขึ้นเยอะ

Logging เป็น Built-in Package ที่เข้ามาช่วยเราในการทำ Log ของโปรแกรมได้ดีมาก ๆ ทั้งแต่ การจัด Level และ การจัดการพวกการแสดงผลต่าง ๆ ที่ถ้าเราไม่ใช้ มันก็ทำได้แหละ แต่เราก็ต้องมาเขียนเองทุกครั้ง มันก็เสียเวลามาก การมีพวกนี้มันก็ลดเวลาในการทำงานของเราได้แหละ พร้อมกับการ Log การทำงาน มันช่วยเราได้มาก เวลาเราเจอปัญหาในการทำงานต่าง ๆ เช่นโปรแกรมอาจจะมี Error บางจุดที่มันไม่ควรเจอ เราก็สามารถใช้ Log จากการใช้งานพวกนี้แหละ ในการวินิฉัย และ แก้ไข ปัญหา ได้ง่ายขึ้นนั่นเอง ดังนั้น Log เถอะเนอะ