การบันทึก Python: บทช่วยสอนเชิงลึก

เผยแพร่แล้ว: 2022-03-11

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

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

แม้จะมีข้อดี แต่โมดูลการบันทึกก็มักจะถูกมองข้าม เนื่องจากต้องใช้เวลาพอสมควรในการตั้งค่าอย่างถูกต้อง และถึงแม้จะสมบูรณ์ในความคิดของฉัน เอกสารการบันทึกอย่างเป็นทางการที่ https://docs.python.org/3/library/logging.html ไม่ได้ให้แนวทางปฏิบัติที่ดีที่สุดในการบันทึกหรือเน้นความประหลาดใจในการบันทึก

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

โปรดทราบว่าข้อมูลโค้ดทั้งหมดในโพสต์ สมมติว่าคุณได้นำเข้าโมดูลการบันทึกแล้ว:

 import logging

แนวคิดสำหรับการบันทึก Python

ส่วนนี้ให้ภาพรวมเกี่ยวกับแนวคิดบางอย่างที่มักพบในโมดูลการบันทึก

ระดับการบันทึก Python

ระดับบันทึกสอดคล้องกับ "ความสำคัญ" ที่บันทึกได้รับ: บันทึก "ข้อผิดพลาด" ควรเร่งด่วนมากกว่าบันทึก "เตือน" ในขณะที่บันทึก "ดีบัก" ควรมีประโยชน์เฉพาะเมื่อดีบั๊กแอปพลิเคชันเท่านั้น

มีหกระดับบันทึกใน Python; แต่ละระดับเชื่อมโยงกับจำนวนเต็มที่ระบุความรุนแรงของบันทึก: NOTSET=0, DEBUG=10, INFO=20, WARN=30, ERROR=40 และ CRITICAL=50

ระดับบันทึกของ Python Logging

ทุกระดับค่อนข้างตรงไปตรงมา (DEBUG < INFO < WARN ) ยกเว้น NOTSET ซึ่งจะกล่าวถึงเรื่องพิเศษในครั้งต่อไป

การจัดรูปแบบการบันทึก Python

ตัวจัดรูปแบบบันทึกโดยทั่วไปทำให้ข้อความบันทึกสมบูรณ์โดยการเพิ่มข้อมูลบริบทเข้าไป อาจเป็นประโยชน์ที่จะรู้ว่าเมื่อใดที่บันทึกถูกส่ง โดยที่ (ไฟล์ Python หมายเลขบรรทัด วิธีการ ฯลฯ) และบริบทเพิ่มเติม เช่น เธรดและกระบวนการ (อาจมีประโยชน์อย่างยิ่งเมื่อทำการดีบั๊กแอปพลิเคชันแบบมัลติเธรด)

ตัวอย่างเช่น เมื่อบันทึก “สวัสดีชาวโลก” ถูกส่งผ่านตัวจัดรูปแบบบันทึก:

 "%(asctime)s — %(name)s — %(levelname)s — %(funcName)s:%(lineno)d — %(message)s"

มันจะกลายเป็น

 2018-02-07 19:47:41,864 - abc - WARNING - <module>:1 - hello world

การจัดรูปแบบข้อความบันทึก Python

Python Logging Handler

ตัวจัดการบันทึกเป็นส่วนประกอบที่เขียน/แสดงบันทึกได้อย่างมีประสิทธิภาพ: แสดงในคอนโซล (ผ่าน StreamHandler) ในไฟล์ (ผ่าน FileHandler) หรือแม้แต่ส่งอีเมลถึงคุณผ่าน SMTPHandler เป็นต้น

ตัวจัดการบันทึกแต่ละรายการมี 2 ช่องสำคัญ:

  • ตัวจัดรูปแบบที่เพิ่มข้อมูลบริบทลงในบันทึก
  • ระดับบันทึกที่กรองบันทึกที่มีระดับต่ำกว่า ดังนั้นตัวจัดการบันทึกที่มีระดับ INFO จะไม่จัดการบันทึก DEBUG

ตัวจัดการการบันทึก Python

ไลบรารีมาตรฐานมีตัวจัดการจำนวนหนึ่งซึ่งน่าจะเพียงพอสำหรับกรณีการใช้งานทั่วไป: https://docs.python.org/3/library/logging.handlers.html#module-logging.handlers ไฟล์ที่พบบ่อยที่สุดคือ StreamHandler และ FileHandler:

 console_handler = logging.StreamHandler() file_handler = logging.FileHandler("filename")

Python Logger

Logger น่าจะเป็นตัวที่ใช้บ่อยที่สุดในโค้ดและซับซ้อนที่สุดเช่นกัน สามารถรับตัวบันทึกใหม่ได้โดย:

 toto_logger = logging.getLogger("toto")

คนตัดไม้มีสามฟิลด์หลัก:

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

กระบวนการบันทึก Python

logger มี ลักษณะเฉพาะ ตามชื่อ หมายความว่าหากมีการสร้างตัวบันทึกชื่อ “toto” การเรียก logging.getLogger("toto") ที่ตามมาจะส่งคืนอ็อบเจ็กต์เดียวกัน:

 assert id(logging.getLogger("toto")) == id(logging.getLogger("toto"))

อย่างที่คุณอาจเดาได้ คนตัดไม้มีลำดับชั้น ที่ด้านบนของลำดับชั้นคือตัวบันทึกรูท ซึ่งสามารถเข้าถึงได้ผ่าน logging.root ตัวบันทึกนี้ถูกเรียกเมื่อมีการใช้วิธีการเช่น logging.debug() โดยค่าเริ่มต้น ระดับบันทึกของรูทคือ WARN ดังนั้นทุกบันทึกที่มีระดับต่ำกว่า (เช่น ผ่าน logging.info("info") ) จะถูกละเว้น ลักษณะเฉพาะอีกอย่างหนึ่งของ root logger คือตัวจัดการเริ่มต้นจะถูกสร้างขึ้นในครั้งแรกที่มีการบันทึกบันทึกที่มีระดับมากกว่า WARN โดยทั่วไปไม่แนะนำให้ใช้ตัวบันทึกรูทโดยตรงหรือโดยอ้อมผ่านวิธีการเช่น logging.debug()

ตามค่าเริ่มต้น เมื่อมีการสร้างตัวบันทึกใหม่ พาเรนต์จะถูกตั้งค่าเป็นตัวบันทึกรูท:

 lab = logging.getLogger("ab") assert lab.parent == logging.root # lab's parent is indeed the root logger

อย่างไรก็ตาม คนตัดไม้ใช้ "เครื่องหมายจุด" ซึ่งหมายความว่าคนตัดไม้ชื่อ "ab" จะเป็นลูกของคนตัดไม้ "a" อย่างไรก็ตาม สิ่งนี้จะเกิดขึ้นก็ต่อเมื่อตัวบันทึก “a” ถูกสร้างขึ้น มิฉะนั้น “ab” parent ยังคงเป็น root

 la = logging.getLogger("a") assert lab.parent == la # lab's parent is now la instead of root

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

โดยค่าเริ่มต้น ตัวบันทึกใหม่มีระดับ NOTSET และเนื่องจากตัวบันทึกรูทมีระดับ WARN ระดับประสิทธิภาพของตัวบันทึกจะเป็น WARN ดังนั้นแม้ว่าตัวบันทึกใหม่จะมีตัวจัดการแนบอยู่ ตัวจัดการเหล่านี้จะไม่ถูกเรียก เว้นแต่ระดับบันทึกจะเกิน WARN:

 toto_logger = logging.getLogger("toto") assert toto_logger.level == logging.NOTSET # new logger has NOTSET level assert toto_logger.getEffectiveLevel() == logging.WARN # and its effective level is the root logger level, ie WARN # attach a console handler to toto_logger console_handler = logging.StreamHandler() toto_logger.addHandler(console_handler) toto_logger.debug("debug") # nothing is displayed as the log level DEBUG is smaller than toto effective level toto_logger.setLevel(logging.DEBUG) toto_logger.debug("debug message") # now you should see "debug message" on screen

โดยค่าเริ่มต้น ระดับตัวบันทึกจะถูกใช้เพื่อตัดสินว่าบันทึกจะผ่าน: หากระดับบันทึกต่ำกว่าระดับตัวบันทึก บันทึกจะถูกละเว้น

แนวทางปฏิบัติที่ดีที่สุดในการบันทึก Python

โมดูลการบันทึกมีประโยชน์มากจริง ๆ แต่มีนิสัยใจคอบางอย่างที่อาจทำให้ปวดหัวเป็นเวลานานสำหรับนักพัฒนา Python ที่ดีที่สุด ต่อไปนี้คือแนวทางปฏิบัติที่ดีที่สุดสำหรับการใช้โมดูลนี้ในความคิดของฉัน:

  • กำหนดค่า root logger แต่อย่าใช้ในโค้ดของคุณ เช่น ห้ามเรียกใช้ฟังก์ชันเช่น logging.info() ซึ่งจริงๆ แล้วเรียก root logger เบื้องหลัง หากคุณต้องการตรวจจับข้อความแสดงข้อผิดพลาดจากไลบรารีที่คุณใช้ ตรวจสอบให้แน่ใจว่าได้กำหนดค่าตัวบันทึกรูทเพื่อเขียนไปยังไฟล์ ตัวอย่างเช่น เพื่อให้การดีบักง่ายขึ้น โดยค่าเริ่มต้น ตัวบันทึกรากจะส่งออกไปยัง stderr เท่านั้น ดังนั้นบันทึกอาจสูญหายได้ง่าย
  • หากต้องการใช้การบันทึก ให้สร้างตัวบันทึกใหม่โดยใช้ logging.getLogger(logger name) ฉันมักจะใช้ __name__ เป็นชื่อคนตัดไม้ แต่ทุกอย่างสามารถใช้ได้ ตราบใดที่มันสอดคล้องกัน ในการเพิ่มตัวจัดการเพิ่มเติม ฉันมักจะมีวิธีที่ส่งคืนตัวบันทึก (คุณสามารถค้นหาส่วนสำคัญได้ที่ https://gist.github.com/nguyenkims/e92df0f8bd49973f0c94bddf36ed7fd0)
 import logging import sys from logging.handlers import TimedRotatingFileHandler FORMATTER = logging.Formatter("%(asctime)s — %(name)s — %(levelname)s — %(message)s") LOG_FILE = "my_app.log" def get_console_handler(): console_handler = logging.StreamHandler(sys.stdout) console_handler.setFormatter(FORMATTER) return console_handler def get_file_handler(): file_handler = TimedRotatingFileHandler(LOG_FILE, when='midnight') file_handler.setFormatter(FORMATTER) return file_handler def get_logger(logger_name): logger = logging.getLogger(logger_name) logger.setLevel(logging.DEBUG) # better to have too much log than not enough logger.addHandler(get_console_handler()) logger.addHandler(get_file_handler()) # with this pattern, it's rarely necessary to propagate the error up to parent logger.propagate = False return logger

หลังจากที่คุณสามารถสร้างตัวบันทึกใหม่และใช้งานได้:

 my_logger = get_logger("my module name") my_logger.debug("a debug message")
  • ใช้คลาส RotatingFileHandler เช่น TimedRotatingFileHandler ที่ใช้ในตัวอย่างแทน FileHandler เนื่องจากจะหมุนไฟล์ให้คุณโดยอัตโนมัติเมื่อไฟล์ถึงขีดจำกัดขนาดหรือทำทุกวัน
  • ใช้เครื่องมือเช่น Sentry, Airbrake, Raygun เป็นต้น เพื่อตรวจจับบันทึกข้อผิดพลาดโดยอัตโนมัติสำหรับคุณ สิ่งนี้มีประโยชน์อย่างยิ่งในบริบทของเว็บแอป ซึ่งบันทึกอาจมีรายละเอียดมาก และบันทึกข้อผิดพลาดอาจสูญหายได้ง่าย ข้อดีอีกประการของการใช้เครื่องมือเหล่านี้คือ คุณจะได้รับรายละเอียดเกี่ยวกับค่าตัวแปรในข้อผิดพลาด เพื่อให้คุณทราบว่า URL ใดทำให้เกิดข้อผิดพลาด ผู้ใช้รายใดเป็นกังวล เป็นต้น

หากคุณสนใจแนวทางปฏิบัติที่ดีที่สุดเพิ่มเติม โปรดอ่าน 10 ข้อผิดพลาดที่พบบ่อยที่สุดที่นักพัฒนา Python ทำโดย Martin Chikilian เพื่อน Toptaler