کتاب آشپزی گزارش‌گیری (Logging Cookbook)

نویسنده:

Vinay Sajip <vinay_sajip at red-dove dot com>

این صفحه حاوی تعدادی دستورالعمل مرتبط با گزارش‌کردن است که در گذشته مفید شناخته شده‌اند. برای پیوندهایی به اطلاعات آموزشی و مرجع، لطفاً منابع دیگر را ببینید.

استفاده از گزارش‌گیری در ماژول‌های متعدد

چندین فراخوانی logging.getLogger('someLogger') ارجاعی به همان شیء گزارش‌گیر برمی‌گردانند. این موضوع نه‌تنها در داخل همان ماژول، بلکه بین ماژول‌ها نیز تا زمانی که در یک فرآیند مفسر پایتون یکسان باشند، صادق است. این امر برای ارجاع‌ها به همان شیء نیز صادق است؛ علاوه بر این، کد برنامه می‌تواند یک گزارش‌گیر والد را در یک ماژول تعریف و پیکربندی کند و یک گزارش‌گیر فرزند را در ماژولی جداگانه ایجاد کند (اما آن را پیکربندی نکند)، و همه‌ی فراخوانی‌های گزارش‌گیر فرزند، به گزارش‌گیر والد منتقل خواهند شد. در ادامه یک ماژول اصلی آمده است:

import logging
import auxiliary_module

# create logger with 'spam_application'
logger = logging.getLogger('spam_application')
logger.setLevel(logging.DEBUG)
# create file handler which logs even debug messages
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
ch.setFormatter(formatter)
# add the handlers to the logger
logger.addHandler(fh)
logger.addHandler(ch)

logger.info('creating an instance of auxiliary_module.Auxiliary')
a = auxiliary_module.Auxiliary()
logger.info('created an instance of auxiliary_module.Auxiliary')
logger.info('calling auxiliary_module.Auxiliary.do_something')
a.do_something()
logger.info('finished auxiliary_module.Auxiliary.do_something')
logger.info('calling auxiliary_module.some_function()')
auxiliary_module.some_function()
logger.info('done with auxiliary_module.some_function()')

در اینجا ماژول کمکی آمده است:

import logging

# create logger
module_logger = logging.getLogger('spam_application.auxiliary')

class Auxiliary:
    def __init__(self):
        self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')
        self.logger.info('creating an instance of Auxiliary')

    def do_something(self):
        self.logger.info('doing something')
        a = 1 + 1
        self.logger.info('done doing something')

def some_function():
    module_logger.info('received a call to "some_function"')

خروجی به این شکل است:

2005-03-23 23:47:11,663 - spam_application - INFO -
   creating an instance of auxiliary_module.Auxiliary
2005-03-23 23:47:11,665 - spam_application.auxiliary.Auxiliary - INFO -
   creating an instance of Auxiliary
2005-03-23 23:47:11,665 - spam_application - INFO -
   created an instance of auxiliary_module.Auxiliary
2005-03-23 23:47:11,668 - spam_application - INFO -
   calling auxiliary_module.Auxiliary.do_something
2005-03-23 23:47:11,668 - spam_application.auxiliary.Auxiliary - INFO -
   doing something
2005-03-23 23:47:11,669 - spam_application.auxiliary.Auxiliary - INFO -
   done doing something
2005-03-23 23:47:11,670 - spam_application - INFO -
   finished auxiliary_module.Auxiliary.do_something
2005-03-23 23:47:11,671 - spam_application - INFO -
   calling auxiliary_module.some_function()
2005-03-23 23:47:11,672 - spam_application.auxiliary - INFO -
   received a call to 'some_function'
2005-03-23 23:47:11,673 - spam_application - INFO -
   done with auxiliary_module.some_function()

ثبت گزارش از چندین نخ

گزارش‌گیری از چندین نخ نیازمند تلاش خاصی نیست. مثال زیر گزارش‌گیری از نخ اصلی (آغازین) و نخی دیگر را نشان می‌دهد:

import logging
import threading
import time

def worker(arg):
    while not arg['stop']:
        logging.debug('Hi from myfunc')
        time.sleep(0.5)

def main():
    logging.basicConfig(level=logging.DEBUG, format='%(relativeCreated)6d %(threadName)s %(message)s')
    info = {'stop': False}
    thread = threading.Thread(target=worker, args=(info,))
    thread.start()
    while True:
        try:
            logging.debug('Hello from main')
            time.sleep(0.75)
        except KeyboardInterrupt:
            info['stop'] = True
            break
    thread.join()

if __name__ == '__main__':
    main()

هنگام اجرا، اسکریپت باید چیزی شبیه به مورد زیر چاپ کند:

   0 Thread-1 Hi from myfunc
   3 MainThread Hello from main
 505 Thread-1 Hi from myfunc
 755 MainThread Hello from main
1007 Thread-1 Hi from myfunc
1507 MainThread Hello from main
1508 Thread-1 Hi from myfunc
2010 Thread-1 Hi from myfunc
2258 MainThread Hello from main
2512 Thread-1 Hi from myfunc
3009 MainThread Hello from main
3013 Thread-1 Hi from myfunc
3515 Thread-1 Hi from myfunc
3761 MainThread Hello from main
4017 Thread-1 Hi from myfunc
4513 MainThread Hello from main
4518 Thread-1 Hi from myfunc

این، خروجی گزارش‌گیری را به‌صورت درهم‌آمیخته، همان‌طور که انتظار می‌رود، نشان می‌دهد. البته این روش برای نخ‌های بیشتری نسبت به آنچه در اینجا نشان داده شده است نیز کار می‌کند.

هندلرها و قالب‌بندهای متعدد

گزارش‌گیرها اشیای ساده پایتون هستند. متد addHandler() هیچ حداقل یا حداکثر سهمیه‌ای برای تعداد هندلرهایی که می‌توانید اضافه کنید، ندارد. گاهی اوقات برای یک برنامه کاربردی مفید خواهد بود که تمام پیام‌ها با تمام سطوح شدت را در یک پرونده متنی گزارش کند و همزمان خطاها یا سطوح بالاتر را در کنسول گزارش کند. برای تنظیم این حالت، کافی است هندلرهای مناسب را پیکربندی کنید. فراخوانی‌های گزارش در کد برنامه بدون تغییر باقی خواهند ماند. در ادامه تغییری جزئی در مثال پیکربندی ساده مبتنی بر ماژول قبلی آمده است:

import logging

logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)
# create file handler which logs even debug messages
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(formatter)
fh.setFormatter(formatter)
# add the handlers to logger
logger.addHandler(ch)
logger.addHandler(fh)

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')

توجه داشته باشید که کد «برنامه» به چند هندلر اهمیتی نمی‌دهد. تنها چیزی که تغییر کرد، افزودن و پیکربندی یک هندلر جدید به نام fh بود.

توانایی ایجاد هندلرهای جدید با فیلترهایی با شدت بالاتر یا پایین‌تر می‌تواند هنگام نوشتن و آزمایش یک برنامه کاربردی بسیار مفید باشد. به جای استفاده از دستورهای print زیاد برای اشکال‌زدایی، از logger.debug استفاده کنید: برخلاف دستورهای print که بعداً مجبور خواهید بود آن‌ها را حذف یا کامنت کنید، دستورهای logger.debug می‌توانند دست‌نخورده در کد منبع باقی بمانند و تا زمانی که دوباره به آن‌ها نیاز دارید، غیرفعال بمانند. در آن زمان، تنها تغییر لازم، تغییر سطح شدت logger و/یا هندلر به debug است.

گزارش‌گیری در چندین مقصد

فرض کنید می‌خواهید گزارش‌ها را با قالب‌های پیام متفاوت و در شرایط مختلف در کنسول و پرونده ثبت کنید. فرض کنید می‌خواهید پیام‌هایی با سطوح DEBUG و بالاتر را در پرونده و پیام‌هایی با سطح INFO و بالاتر را در کنسول ثبت کنید. همچنین فرض کنید پرونده باید شامل برچسب‌های زمانی باشد، اما پیام‌های کنسول نباید شامل برچسب‌های زمانی باشند. در ادامه، چگونگی دستیابی به این هدف آمده است:

import logging

# set up logging to file - see previous section for more details
logging.basicConfig(level=logging.DEBUG,
                    format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',
                    datefmt='%m-%d %H:%M',
                    filename='/tmp/myapp.log',
                    filemode='w')
# define a Handler which writes INFO messages or higher to the sys.stderr
console = logging.StreamHandler()
console.setLevel(logging.INFO)
# set a format which is simpler for console use
formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
# tell the handler to use this format
console.setFormatter(formatter)
# add the handler to the root logger
logging.getLogger().addHandler(console)

# Now, we can log to the root logger, or any other logger. First the root...
logging.info('Jackdaws love my big sphinx of quartz.')

# Now, define a couple of other loggers which might represent areas in your
# application:

logger1 = logging.getLogger('myapp.area1')
logger2 = logging.getLogger('myapp.area2')

logger1.debug('Quick zephyrs blow, vexing daft Jim.')
logger1.info('How quickly daft jumping zebras vex.')
logger2.warning('Jail zesty vixen who grabbed pay from quack.')
logger2.error('The five boxing wizards jump quickly.')

هنگامی که این را اجرا می‌کنید، در کنسول خواهید دید

root        : INFO     Jackdaws love my big sphinx of quartz.
myapp.area1 : INFO     How quickly daft jumping zebras vex.
myapp.area2 : WARNING  Jail zesty vixen who grabbed pay from quack.
myapp.area2 : ERROR    The five boxing wizards jump quickly.

و در پرونده چیزی شبیه به این خواهید دید

10-22 22:19 root         INFO     Jackdaws love my big sphinx of quartz.
10-22 22:19 myapp.area1  DEBUG    Quick zephyrs blow, vexing daft Jim.
10-22 22:19 myapp.area1  INFO     How quickly daft jumping zebras vex.
10-22 22:19 myapp.area2  WARNING  Jail zesty vixen who grabbed pay from quack.
10-22 22:19 myapp.area2  ERROR    The five boxing wizards jump quickly.

همان‌طور که می‌بینید، پیام DEBUG فقط در پرونده نمایش داده می‌شود. سایر پیام‌ها به هر دو مقصد ارسال می‌شوند.

این مثال از هندلرهای کنسول و پرونده استفاده می‌کند، اما شما می‌توانید از هر تعداد و ترکیبی از هندلرها که بخواهید استفاده کنید.

توجه داشته باشید که انتخاب نام پرونده گزارش /tmp/myapp.log در بالا، به معنای استفاده از یک مکان استاندارد برای پرونده‌های موقت در سیستم‌های POSIX است. در ویندوز، ممکن است لازم باشد نام پوشه متفاوتی را برای گزارش انتخاب کنید؛ فقط اطمینان حاصل کنید که پوشه وجود دارد و شما دسترسی لازم برای ایجاد و به‌روزرسانی پرونده‌ها در آن را دارید.

مدیریت سفارشی سطح‌ها

گاهی ممکن است بخواهید کاری کمی متفاوت از روش استاندارد پردازش سطوح در هندلرها انجام دهید، که در آن تمام سطوح بالاتر از یک آستانه توسط یک هندلر پردازش می‌شوند. برای این کار، باید از فیلترها استفاده کنید. بیایید سناریویی را بررسی کنیم که می‌خواهید موارد را به‌صورت زیر مرتب کنید:

• پیام‌هایی با شدت INFO و WARNING را به sys.stdout ارسال کنید

• پیام‌های با شدت ERROR و بالاتر را به sys.stderr ارسال کنید

• پیام‌هایی با شدت DEBUG و بالاتر را به پرونده app.log ارسال کنید

فرض کنید گزارش‌گیری را با JSON زیر پیکربندی می‌کنید:

{
    "version": 1,
    "disable_existing_loggers": false,
    "formatters": {
        "simple": {
            "format": "%(levelname)-8s - %(message)s"
        }
    },
    "handlers": {
        "stdout": {
            "class": "logging.StreamHandler",
            "level": "INFO",
            "formatter": "simple",
            "stream": "ext://sys.stdout"
        },
        "stderr": {
            "class": "logging.StreamHandler",
            "level": "ERROR",
            "formatter": "simple",
            "stream": "ext://sys.stderr"
        },
        "file": {
            "class": "logging.FileHandler",
            "formatter": "simple",
            "filename": "app.log",
            "mode": "w"
        }
    },
    "root": {
        "level": "DEBUG",
        "handlers": [
            "stderr",
            "stdout",
            "file"
        ]
    }
}

این پیکربندی تقریباً آنچه می‌خواهیم انجام می‌دهد، با این استثنا که sys.stdout پیام‌هایی با شدت ERROR را نشان می‌دهد و تنها رویدادهایی با این شدت و بالاتر، به‌همراه پیام‌های INFO و WARNING نیز پیگیری می‌شوند. برای جلوگیری از این موضوع، می‌توانیم فیلتری تنظیم کنیم که آن پیام‌ها را حذف کند و آن را به هندلر مربوطه اضافه کنیم. این کار را می‌توان با افزودن یک بخش filters هم‌سطح با formatters و handlers پیکربندی کرد:

{
    "filters": {
        "warnings_and_below": {
            "()" : "__main__.filter_maker",
            "level": "WARNING"
        }
    }
}

و تغییر بخش مربوط به هندلر stdout برای افزودن آن:

{
    "stdout": {
        "class": "logging.StreamHandler",
        "level": "INFO",
        "formatter": "simple",
        "stream": "ext://sys.stdout",
        "filters": ["warnings_and_below"]
    }
}

یک فیلتر فقط یک تابع است، بنابراین می‌توانیم filter_maker (یک تابع کارخانه) را به‌صورت زیر تعریف کنیم:

def filter_maker(level):
    level = getattr(logging, level)

    def filter(record):
        return record.levelno <= level

    return filter

این، آرگومان رشته‌ای داده‌شده را به یک سطح عددی تبدیل می‌کند و تابعی را برمی‌گرداند که فقط در صورتی True را برمی‌گرداند که سطح رکورد داده‌شده برابر با سطح مشخص‌شده یا پایین‌تر از آن باشد. توجه داشته باشید که در این مثال، filter_maker را در یک اسکریپت آزمایشی به نام main.py تعریف کرده‌ام که آن را از خط فرمان اجرا می‌کنم؛ بنابراین ماژول آن __main__ خواهد بود؛ از این رو __main__.filter_maker در پیکربندی فیلتر آمده است. اگر آن را در ماژول دیگری تعریف کنید، باید آن را تغییر دهید.

با افزودن فیلتر، می‌توانیم main.py را اجرا کنیم، که به‌طور کامل به این صورت است:

import json
import logging
import logging.config

CONFIG = '''
{
    "version": 1,
    "disable_existing_loggers": false,
    "formatters": {
        "simple": {
            "format": "%(levelname)-8s - %(message)s"
        }
    },
    "filters": {
        "warnings_and_below": {
            "()" : "__main__.filter_maker",
            "level": "WARNING"
        }
    },
    "handlers": {
        "stdout": {
            "class": "logging.StreamHandler",
            "level": "INFO",
            "formatter": "simple",
            "stream": "ext://sys.stdout",
            "filters": ["warnings_and_below"]
        },
        "stderr": {
            "class": "logging.StreamHandler",
            "level": "ERROR",
            "formatter": "simple",
            "stream": "ext://sys.stderr"
        },
        "file": {
            "class": "logging.FileHandler",
            "formatter": "simple",
            "filename": "app.log",
            "mode": "w"
        }
    },
    "root": {
        "level": "DEBUG",
        "handlers": [
            "stderr",
            "stdout",
            "file"
        ]
    }
}
'''

def filter_maker(level):
    level = getattr(logging, level)

    def filter(record):
        return record.levelno <= level

    return filter

logging.config.dictConfig(json.loads(CONFIG))
logging.debug('A DEBUG message')
logging.info('An INFO message')
logging.warning('A WARNING message')
logging.error('An ERROR message')
logging.critical('A CRITICAL message')

و پس از اجرای آن به این صورت:

python main.py 2>stderr.log >stdout.log

می‌توانیم ببینیم که نتایج مطابق انتظار هستند:

$ more *.log
::::::::::::::
app.log
::::::::::::::
DEBUG    - A DEBUG message
INFO     - An INFO message
WARNING  - A WARNING message
ERROR    - An ERROR message
CRITICAL - A CRITICAL message
::::::::::::::
stderr.log
::::::::::::::
ERROR    - An ERROR message
CRITICAL - A CRITICAL message
::::::::::::::
stdout.log
::::::::::::::
INFO     - An INFO message
WARNING  - A WARNING message

مثال سرور پیکربندی

در اینجا نمونه‌ای از یک ماژول که از سرور پیکربندی گزارش‌گیری (logging configuration server) استفاده می‌کند، آمده است:

import logging
import logging.config
import time
import os

# read initial config file
logging.config.fileConfig('logging.conf')

# create and start listener on port 9999
t = logging.config.listen(9999)
t.start()

logger = logging.getLogger('simpleExample')

try:
    # loop through logging calls to see the difference
    # new configurations make, until Ctrl+C is pressed
    while True:
        logger.debug('debug message')
        logger.info('info message')
        logger.warning('warn message')
        logger.error('error message')
        logger.critical('critical message')
        time.sleep(5)
except KeyboardInterrupt:
    # cleanup
    logging.config.stopListening()
    t.join()

و در اینجا اسکریپتی آمده است که یک نام پرونده می‌گیرد و آن پرونده را به‌عنوان پیکربندی جدید گزارش‌گیری، به‌همراه طول کدگذاری‌شده‌ی دودویی که به‌درستی پیش از آن قرار گرفته است، به سرور ارسال می‌کند:

#!/usr/bin/env python
import socket, sys, struct

with open(sys.argv[1], 'rb') as f:
    data_to_send = f.read()

HOST = 'localhost'
PORT = 9999
s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
print('connecting...')
s.connect((HOST, PORT))
print('sending config...')
s.send(struct.pack('>L', len(data_to_send)))
s.send(data_to_send)
s.close()
print('complete')

مدیریت هندلرهایی که مسدود می‌کنند

گاهی اوقات لازم است کاری کنید که هندلرهای گزارش‌گیری (logging handlers) کار خود را بدون مسدود کردن نخی که از آن گزارش‌گیری می‌کنید، انجام دهند. این حالت در برنامه‌های وب رایج است، هرچند البته در سناریوهای دیگر نیز رخ می‌دهد.

یکی از عوامل رایج که رفتار کندی از خود نشان می‌دهد، SMTPHandler است: ارسال ایمیل‌ها ممکن است به دلایل متعددی خارج از کنترل توسعه‌دهنده زمان زیادی ببرد (برای مثال، زیرساخت ایمیل یا شبکه با عملکرد ضعیف). اما تقریباً هر هندلر مبتنی بر شبکه‌ای می‌تواند مسدودکننده باشد: حتی یک عملیات SocketHandler ممکن است در پشت صحنه یک پرس‌وجوی DNS انجام دهد که بیش از حد کند است (و این پرس‌وجو می‌تواند در عمق کد کتابخانه سوکت، پایین‌تر از لایه پایتون و خارج از کنترل شما باشد).

یک راه‌حل، استفاده از یک رویکرد دوبخشی است. برای بخش نخست، فقط یک QueueHandler را به آن دسته از گزارش‌گیرها که از نخ‌های حساس به عملکرد به آن‌ها دسترسی می‌شود، متصل کنید. آن‌ها به‌سادگی در صف خود می‌نویسند؛ صفی که می‌توان آن را با ظرفیتی به‌اندازه کافی بزرگ تنظیم کرد یا بدون کران بالا برای اندازه‌اش مقداردهی اولیه کرد. نوشتن در صف معمولاً به‌سرعت پذیرفته می‌شود، هرچند احتمالاً لازم است استثنای queue.Full را به‌عنوان اقدام احتیاطی در کد خود مهار کنید. اگر توسعه‌دهنده کتابخانه هستید و نخ‌های حساس به عملکرد در کد خود دارید، حتماً این موضوع را (به‌همراه پیشنهادی مبنی بر اینکه فقط QueueHandlers را به گزارش‌گیرها شما متصل کنند) برای بهره‌مندی سایر توسعه‌دهندگانی که از کد شما استفاده خواهند کرد، مستند کنید.

بخش دوم راه‌حل QueueListener است که به‌عنوان همتای QueueHandler طراحی شده است. یک QueueListener بسیار ساده است: یک صف و چند هندلر به آن داده می‌شود و آن یک نخ داخلی راه‌اندازی می‌کند که به صف خود برای دریافت LogRecords ارسال‌شده از QueueHandlers (یا هر منبع دیگری از LogRecords، در این خصوص) گوش می‌دهد. LogRecords از صف حذف می‌شوند و برای پردازش به هندلرها داده می‌شوند.

مزیت داشتن یک کلاس QueueListener جداگانه این است که می‌توانید از یک نمونه‌ی واحد برای سرویس‌دهی به چندین QueueHandlers استفاده کنید. این کار از نظر مصرف منابع به‌صرفه‌تر از، مثلاً، داشتن نسخه‌های مبتنی بر نخ از کلاس‌های هندلر موجود است؛ نسخه‌هایی که به ازای هر handler یک نخ را بدون هیچ مزیت خاصی مصرف می‌کردند.

در ادامه مثالی از استفاده از این دو کلاس آمده است (ایمپورت‌ها حذف شده‌اند):

que = queue.Queue(-1)  # no limit on size
queue_handler = QueueHandler(que)
handler = logging.StreamHandler()
listener = QueueListener(que, handler)
root = logging.getLogger()
root.addHandler(queue_handler)
formatter = logging.Formatter('%(threadName)s: %(message)s')
handler.setFormatter(formatter)
listener.start()
# The log output will display the thread which generated
# the event (the main thread) rather than the internal
# thread which monitors the internal queue. This is what
# you want to happen.
root.warning('Look out!')
listener.stop()

که با اجرای آن، خروجی زیر تولید می‌شود:

MainThread: Look out!

توجه

اگرچه بحث پیشین به‌طور مشخص درباره‌ی کد ناهمگام نبود، بلکه درباره‌ی هندلرهای کند گزارش‌گیری بود، باید توجه داشت که هنگام گزارش‌گیری از کد ناهمگام، هندلرهای شبکه و حتی پرونده می‌توانند به مشکلاتی منجر شوند (مسدود کردن حلقه‌ی رویداد)، زیرا بخشی از گزارش‌گیری از درونی asyncio انجام می‌شود. اگر در یک برنامه از هرگونه کد ناهمگام استفاده می‌شود، ممکن است بهتر باشد برای گزارش‌گیری از روش بالا استفاده کنید، تا هر کد مسدودکننده‌ای فقط در نخ QueueListener اجرا شود.

تغییر یافته در نسخه‌ی 3.5: پیش از پایتون 3.5، QueueListener همیشه هر پیام دریافت‌شده از صف را به هر هندلر که شنونده با آن مقداردهی اولیه شده بود، ارسال می‌کرد. (این به این دلیل بود که فرض می‌شد تمام پالایش سطح در سمت دیگر، جایی که صف پر می‌شود، انجام می‌شود.) از 3.5 به بعد، می‌توان این رفتار را با ارسال یک آرگومان کلیدواژه‌ای respect_handler_level=True به سازنده‌ی شنونده تغییر داد. هنگامی که این کار انجام شود، شنونده سطح هر پیام را با سطح مدیر مقایسه می‌کند و تنها در صورتی یک پیام را به یک مدیر ارسال می‌کند که این کار مناسب باشد.

تغییر یافته در نسخه‌ی 3.14: می‌توان QueueListener را از طریق دستور with راه‌اندازی (و متوقف) کرد. برای مثال:

with QueueListener(que, handler) as listener:
    # The queue listener automatically starts
    # when the 'with' block is entered.
    pass
# The queue listener automatically stops once
# the 'with' block is exited.

ارسال و دریافت رویدادهای گزارش در سراسر شبکه

فرض کنید می‌خواهید رویدادهای گزارش را از طریق شبکه ارسال کنید و آن‌ها را در سمت دریافت‌کننده پردازش کنید. یک راه ساده برای انجام این کار، اتصال یک نمونه از SocketHandler به گزارش‌گیر ریشه در سمت فرستنده است:

import logging, logging.handlers

rootLogger = logging.getLogger()
rootLogger.setLevel(logging.DEBUG)
socketHandler = logging.handlers.SocketHandler('localhost',
                    logging.handlers.DEFAULT_TCP_LOGGING_PORT)
# don't bother with a formatter, since a socket handler sends the event as
# an unformatted pickle
rootLogger.addHandler(socketHandler)

# Now, we can log to the root logger, or any other logger. First the root...
logging.info('Jackdaws love my big sphinx of quartz.')

# Now, define a couple of other loggers which might represent areas in your
# application:

logger1 = logging.getLogger('myapp.area1')
logger2 = logging.getLogger('myapp.area2')

logger1.debug('Quick zephyrs blow, vexing daft Jim.')
logger1.info('How quickly daft jumping zebras vex.')
logger2.warning('Jail zesty vixen who grabbed pay from quack.')
logger2.error('The five boxing wizards jump quickly.')

در سمت دریافت، می‌توانید با استفاده از ماژول socketserver یک گیرنده راه‌اندازی کنید. در ادامه یک مثال پایه‌ی کارآمد آمده است:

import pickle
import logging
import logging.handlers
import socketserver
import struct


class LogRecordStreamHandler(socketserver.StreamRequestHandler):
    """هندلر برای یک درخواست گزارش‌گیری جریانی.

    این کلاس اساساً رکورد را با استفاده از هر سیاست گزارش‌گیری که به‌صورت محلی
    پیکربندی‌شده است، ثبت می‌کند.
    """

    def handle(self):
        """
        به چندین درخواست رسیدگی می‌کند - انتظار می‌رود هر کدام شامل یک طول ۴ بایتی باشد
        که پس از آن LogRecord در قالب pickle می‌آید. رکورد را مطابق هر سیاستی که
        به‌صورت محلی پیکربندی‌شده است، ثبت می‌کند.
        """
        while True:
            chunk = self.connection.recv(4)
            if len(chunk) < 4:
                break
            slen = struct.unpack('>L', chunk)[0]
            chunk = self.connection.recv(slen)
            while len(chunk) < slen:
                chunk = chunk + self.connection.recv(slen - len(chunk))
            obj = self.unPickle(chunk)
            record = logging.makeLogRecord(obj)
            self.handleLogRecord(record)

    def unPickle(self, data):
        return pickle.loads(data)

    def handleLogRecord(self, record):
        # if a name is specified, we use the named logger rather than the one
        # implied by the record.
        if self.server.logname is not None:
            name = self.server.logname
        else:
            name = record.name
        logger = logging.getLogger(name)
        # N.B. EVERY record gets logged. This is because Logger.handle
        # is normally called AFTER logger-level filtering. If you want
        # to do filtering, do it at the client end to save wasting
        # cycles and network bandwidth!
        logger.handle(record)

class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):
    """
    دریافت‌کننده ساده گزارش‌گیری مبتنی بر سوکت TCP که برای آزمایش مناسب است.
    """

    allow_reuse_address = True

    def __init__(self, host='localhost',
                 port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,
                 handler=LogRecordStreamHandler):
        socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)
        self.abort = 0
        self.timeout = 1
        self.logname = None

    def serve_until_stopped(self):
        import select
        abort = 0
        while not abort:
            rd, wr, ex = select.select([self.socket.fileno()],
                                       [], [],
                                       self.timeout)
            if rd:
                self.handle_request()
            abort = self.abort

def main():
    logging.basicConfig(
        format='%(relativeCreated)5d %(name)-15s %(levelname)-8s %(message)s')
    tcpserver = LogRecordSocketReceiver()
    print('About to start TCP server...')
    tcpserver.serve_until_stopped()

if __name__ == '__main__':
    main()

ابتدا سرور و سپس کلاینت را اجرا کنید. در سمت کلاینت، هیچ چیزی در کنسول چاپ نمی‌شود؛ در سمت سرور، باید چیزی شبیه به این ببینید:

About to start TCP server...
   59 root            INFO     Jackdaws love my big sphinx of quartz.
   59 myapp.area1     DEBUG    Quick zephyrs blow, vexing daft Jim.
   69 myapp.area1     INFO     How quickly daft jumping zebras vex.
   69 myapp.area2     WARNING  Jail zesty vixen who grabbed pay from quack.
   69 myapp.area2     ERROR    The five boxing wizards jump quickly.

توجه داشته باشید که استفاده از pickle در برخی حالت‌ها دارای مسائل امنیتی است. اگر این مسائل شما را تحت تأثیر قرار می‌دهند، می‌توانید با بازنویسی متد makePickle() و پیاده‌سازی روش جایگزین خود در آن، و همچنین تطبیق اسکریپت بالا برای استفاده از سریال‌سازی جایگزین خود، از یک روش سریال‌سازی جایگزین استفاده کنید.

اجرای یک شنونده‌ی سوکت گزارش‌گیری در محیط عملیاتی

برای اجرای یک شنونده‌ی گزارش‌گیری در محیط عملیاتی، ممکن است لازم باشد از یک ابزار مدیریت فرایند مانند Supervisor استفاده کنید. در اینجا یک Gist ارائه شده است که پرونده‌های پایه را برای اجرای قابلیت فوق با استفاده از Supervisor فراهم می‌کند. این مجموعه شامل پرونده‌های زیر است:

پرونده	هدف
prepare.sh	یک اسکریپت Bash برای آماده‌سازی محیط جهت آزمون
supervisor.conf	پرونده پیکربندی Supervisor، که دارای مدخل‌هایی برای شنونده و یک برنامه وب چندفرایندی است
ensure_app.sh	یک اسکریپت Bash برای اطمینان از اینکه Supervisor با پیکربندی بالا در حال اجرا است
log_listener.py	برنامه‌ی شنونده سوکت که رویدادهای گزارش را دریافت می‌کند و آن‌ها را در یک پرونده ثبت می‌کند
main.py	یک برنامه وب ساده که گزارش‌گیری را از طریق سوکتی متصل به شنونده انجام می‌دهد
webapp.json	یک پرونده‌ی پیکربندی JSON برای برنامه‌ی وب
client.py	یک اسکریپت پایتونی برای آزمودن وب‌اپلیکیشن

برنامه کاربردی وب از Gunicorn استفاده می‌کند، که سرور برنامه کاربردی وب محبوبی است و چند فرایند کارگر (worker process) را برای رسیدگی به درخواست‌ها راه‌اندازی می‌کند. این پیکربندی نمونه نشان می‌دهد که کارگرها چگونه می‌توانند بدون تداخل با یکدیگر در یک پرونده گزارش مشترک بنویسند --- همه‌ی آن‌ها از طریق شنونده‌ی سوکت (socket listener) عبور می‌کنند.

برای آزمایش این پرونده‌ها، در یک محیط POSIX موارد زیر را انجام دهید:

1. the Gist را با استفاده از دکمه‌ی Download ZIP به‌صورت یک آرشیو ZIP دانلود کنید.

2. پرونده‌های بالا را از بایگانی به یک پوشه موقت استخراج کنید.

3. در پوشه‌ی scratch، دستور bash prepare.sh را برای آماده‌سازی اجرا کنید. این دستور یک زیرپوشه‌ی run برای نگهداری پرونده‌های مربوط به Supervisor و پرونده‌های گزارش، و یک زیرپوشه‌ی venv برای نگهداری یک محیط مجازی ایجاد می‌کند که bottle، gunicorn و supervisor در آن نصب می‌شوند.

4. برای اطمینان از اینکه Supervisor با پیکربندی بالا در حال اجرا است، bash ensure_app.sh را اجرا کنید.

5. برای آزمایش برنامه وب، venv/bin/python client.py را اجرا کنید، که منجر به نوشته شدن رکوردها در گزارش می‌شود.

6. پرونده‌های گزارش را در زیرپوشه‌ی run بررسی کنید. شما باید جدیدترین سطرهای گزارش را در پرونده‌هایی که با الگوی app.log* مطابقت دارند ببینید. این سطرها در هیچ ترتیب خاصی نخواهند بود، زیرا به‌صورت همزمان توسط فرآیندهای کارگر مختلف به‌شکلی غیرقطعی پردازش شده‌اند.

7. شما می‌توانید با اجرای venv/bin/supervisorctl -c supervisor.conf shutdown، شنونده و برنامه کاربردی وب را خاموش کنید.

ممکن است لازم باشد پرونده‌های پیکربندی را تنظیم کنید، در صورتی که، هرچند بعید، پورت‌های پیکربندی‌شده با مورد دیگری در محیط آزمایشی شما تداخل داشته باشند.

پیکربندی پیش‌فرض از یک سوکت TCP روی پورت ۹۰۲۰ استفاده می‌کند. شما می‌توانید با انجام موارد زیر به‌جای سوکت TCP از یک سوکت دامنه یونیکس استفاده کنید:

1. در listener.json، یک کلید socket همراه با مسیر سوکت دامنه (domain socket) که می‌خواهید از آن استفاده کنید، اضافه کنید. اگر این کلید وجود داشته باشد، شنونده روی سوکت دامنه مربوطه گوش می‌دهد و روی سوکت TCP گوش نمی‌دهد (کلید port نادیده گرفته می‌شود).

2. در webapp.json، دیکشنری پیکربندی هندلری سوکت (socket handler) را تغییر دهید تا مقدار host مسیر سوکت دامنه (domain socket) باشد و مقدار port را روی null تنظیم کنید.

افزودن اطلاعات زمینه‌ای به خروجی گزارش شما

گاهی می‌خواهید خروجی گزارش علاوه بر پارامترهای ارسال‌شده به فراخوانی گزارش، حاوی اطلاعات زمینه‌ای باشد. برای مثال، در یک برنامه شبکه‌ای، ممکن است مطلوب باشد که اطلاعات مختص کلاینت در گزارش ثبت شود (مثلاً نام کاربری کلاینت راه دور یا نشانی IP). اگرچه می‌توانید برای دستیابی به این هدف از پارامتر extra استفاده کنید، اما ارسال اطلاعات به این روش همیشه آسان نیست. هرچند ممکن است ایجاد نمونه‌های Logger به‌ازای هر اتصال وسوسه‌انگیز باشد، اما این کار ایده خوبی نیست؛ زیرا این نمونه‌ها زباله‌روبی نمی‌شوند. هرچند این موضوع در عمل مشکلی ایجاد نمی‌کند، اما وقتی تعداد نمونه‌های Logger به سطح دانه‌بندی‌ای وابسته باشد که می‌خواهید هنگام گزارش کردن یک برنامه از آن استفاده کنید، اگر تعداد نمونه‌های Logger عملاً بی‌کران شود، مدیریت آن می‌تواند دشوار باشد.

استفاده از LoggerAdapters برای انتقال اطلاعات زمینه‌ای

راهی آسان برای ارسال اطلاعات زمینه‌ای تا همراه با اطلاعات رویداد گزارش خروجی داده شود، استفاده از کلاس LoggerAdapter است. این کلاس به‌گونه‌ای طراحی شده است که شبیه یک Logger به نظر برسد، به‌طوری که شما می‌توانید debug()، info()، warning()، error()، exception()، critical() و log() را فراخوانی کنید. این متدها امضاهای یکسانی با همتایان خود در Logger دارند، بنابراین می‌توانید از نمونه‌های این دو نوع به‌جای یکدیگر استفاده کنید.

هنگامی که یک نمونه از LoggerAdapter ایجاد می‌کنید، به آن یک نمونه از Logger و یک شیء دیکشنری‌مانند که حاوی اطلاعات زمینه‌ای شما است می‌دهید. هنگامی که یکی از متدهای گزارش‌گیری را روی یک نمونه از LoggerAdapter فراخوانی می‌کنید، آن فراخوانی را به نمونه زیرین Logger که به سازنده‌اش داده شده است واگذار می‌کند و ترتیبی می‌دهد که اطلاعات زمینه‌ای در فراخوانی واگذارشده ارسال شود. در ادامه قطعه‌ای از کد LoggerAdapter آمده است:

def debug(self, msg, /, *args, **kwargs):
    """
    یک فراخوانی debug را پس از افزودن اطلاعات زمینه‌ای از این نمونه‌ی آداپتور،
    به گزارش‌گیر زیرین محول می‌کند.
    """
    msg, kwargs = self.process(msg, kwargs)
    self.logger.debug(msg, *args, **kwargs)

متد process() در کلاس LoggerAdapter جایی است که اطلاعات زمینه‌ای به خروجی گزارش افزوده می‌شود. پیام و آرگومان‌های کلیدواژه‌ای فراخوانی گزارش به آن داده می‌شوند، و این متد نسخه‌های (احتمالاً) تغییریافته‌ی آن‌ها را برای استفاده در فراخوانی گزارش‌گیر زیربنایی بازمی‌گرداند. پیاده‌سازی پیش‌فرض این متد، پیام را دست‌نخورده باقی می‌گذارد، اما یک کلید 'extra' در آرگومان کلیدواژه‌ای درج می‌کند که مقدار آن شیء دیکشنری‌مانندی است که به سازنده داده شده است. البته، اگر در فراخوانی آداپتور یک آرگومان کلیدواژه‌ای 'extra' داده باشید، بدون هشدار بازنویسی خواهد شد.

مزیت استفاده از 'extra' این است که مقادیر موجود در شیء دیکشنری‌مانند در __dict__ نمونه‌ی LogRecord ادغام می‌شوند، بنابراین می‌توانید از رشته‌های سفارشی همراه با نمونه‌های Formatter خود استفاده کنید که از کلیدهای شیء دیکشنری‌مانند آگاه هستند. اگر به متد متفاوتی نیاز دارید، برای مثال اگر می‌خواهید اطلاعات زمینه‌ای را به ابتدای رشته پیام اضافه کنید یا به انتهای آن بیفزایید، کافی است یک زیرکلاس از LoggerAdapter بسازید و process() را بازنویسی کنید تا آنچه نیاز دارید انجام شود. در ادامه یک مثال ساده آمده است:

class CustomAdapter(logging.LoggerAdapter):
    """
    این آداپتور نمونه انتظار دارد شیء دیکشنری‌مانندِ ارسال‌شده دارای کلید 'connid' باشد،
    که مقدار آن داخل کروشه به ابتدای پیام گزارش اضافه می‌شود.
    """
    def process(self, msg, kwargs):
        return '[%s] %s' % (self.extra['connid'], msg), kwargs

که می‌توانید به این شکل استفاده کنید:

logger = logging.getLogger(__name__)
adapter = CustomAdapter(logger, {'connid': some_conn_id})

سپس برای هر رویدادی که در آداپتور ثبت کنید، مقدار some_conn_id به ابتدای پیام‌های گزارش اضافه می‌شود.

استفاده از اشیایی غیر از دیکشنری‌ها برای انتقال اطلاعات زمینه‌ای

شما نیازی به ارسال یک دیکشنری واقعی به LoggerAdapter ندارید؛ می‌توانید نمونه‌ای از کلاسی که __getitem__ و __iter__ را پیاده‌سازی می‌کند ارسال کنید، به‌طوری که از نظر logging شبیه یک دیکشنری به نظر برسد. این در صورتی مفید است که بخواهید مقادیر را به‌صورت پویا تولید کنید (در حالی که مقادیر در یک دیکشنری ثابت خواهند بود).

استفاده از فیلترها برای انتقال اطلاعات زمینه‌ای

شما همچنین می‌توانید اطلاعات زمینه‌ای را با استفاده از یک Filter تعریف‌شده توسط کاربر به خروجی گزارش اضافه کنید. نمونه‌های Filter مجازند LogRecords های ارسال‌شده به خود را تغییر دهند، از جمله افزودن ویژگی‌های اضافی که سپس می‌توان آن‌ها را با استفاده از یک رشته قالب مناسب خروجی داد، یا در صورت نیاز با یک Formatter سفارشی.

برای مثال در یک برنامه وب، می‌توان درخواست در حال پردازش (یا حداقل بخش‌های جالب‌توجه آن) را در یک متغیر محلی نخ (threadlocal، threading.local) ذخیره کرد و سپس از یک Filter به آن دسترسی پیدا کرد تا مثلاً اطلاعاتی از درخواست — مثلاً نشانی IP راه‌دور و نام کاربری کاربر راه‌دور — با استفاده از نام ویژگی‌های 'ip' و 'user'، همان‌طور که در مثال LoggerAdapter بالا نشان داده شد، به LogRecord اضافه شود. در این صورت، می‌توان از همان رشته قالب برای گرفتن خروجی مشابه آنچه در بالا نشان داده شد استفاده کرد. در ادامه یک اسکریپت نمونه آمده است:

import logging
from random import choice

class ContextFilter(logging.Filter):
    """
    This is a filter which injects contextual information into the log.

    Rather than use actual contextual information, we just use random
    data in this demo.
    """

    USERS = ['jim', 'fred', 'sheila']
    IPS = ['123.231.231.123', '127.0.0.1', '192.168.0.1']

    def filter(self, record):

        record.ip = choice(ContextFilter.IPS)
        record.user = choice(ContextFilter.USERS)
        return True

if __name__ == '__main__':
    levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)
    logging.basicConfig(level=logging.DEBUG,
                        format='%(asctime)-15s %(name)-5s %(levelname)-8s IP: %(ip)-15s User: %(user)-8s %(message)s')
    a1 = logging.getLogger('a.b.c')
    a2 = logging.getLogger('d.e.f')

    f = ContextFilter()
    a1.addFilter(f)
    a2.addFilter(f)
    a1.debug('A debug message')
    a1.info('An info message with %s', 'some parameters')
    for x in range(10):
        lvl = choice(levels)
        lvlname = logging.getLevelName(lvl)
        a2.log(lvl, 'A message at %s level with %d %s', lvlname, 2, 'parameters')

که هنگام اجرا، چیزی شبیه به این تولید می‌کند:

2010-09-06 22:38:15,292 a.b.c DEBUG    IP: 123.231.231.123 User: fred     A debug message
2010-09-06 22:38:15,300 a.b.c INFO     IP: 192.168.0.1     User: sheila   An info message with some parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1       User: sheila   A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f ERROR    IP: 127.0.0.1       User: jim      A message at ERROR level with 2 parameters
2010-09-06 22:38:15,300 d.e.f DEBUG    IP: 127.0.0.1       User: sheila   A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,300 d.e.f ERROR    IP: 123.231.231.123 User: fred     A message at ERROR level with 2 parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 192.168.0.1     User: jim      A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1       User: sheila   A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f DEBUG    IP: 192.168.0.1     User: jim      A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,301 d.e.f ERROR    IP: 127.0.0.1       User: sheila   A message at ERROR level with 2 parameters
2010-09-06 22:38:15,301 d.e.f DEBUG    IP: 123.231.231.123 User: fred     A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,301 d.e.f INFO     IP: 123.231.231.123 User: fred     A message at INFO level with 2 parameters

استفاده از contextvars

از پایتون 3.7، ماژول contextvars ذخیره‌سازی محلی در زمینه (context-local storage) را فراهم کرده است که برای نیازهای پردازشی هر دو threading و asyncio به کار می‌رود. بنابراین، این نوع ذخیره‌سازی ممکن است عموماً به متغیرهای نخ‌محلی (thread-locals) ترجیح داده شود. مثال زیر نشان می‌دهد که در یک محیط چندنخی، چگونه می‌توان گزارش‌ها را با اطلاعات زمینه‌ای پر کرد، از جمله، برای مثال، با ویژگی‌های درخواستی که توسط برنامه‌های وب مدیریت می‌شوند.

برای روشن‌تر شدن موضوع، فرض کنید چند برنامه‌ی وب مختلف دارید که هرکدام مستقل از دیگری هستند، اما در یک فرایند پایتون مشترک اجرا می‌شوند و از یک کتابخانه‌ی مشترک میان آن‌ها استفاده می‌کنند. چگونه هرکدام از این برنامه‌ها می‌توانند گزارش مستقل خود را داشته باشند، به‌طوری‌که تمام پیام‌های گزارش‌دهی از کتابخانه (و سایر کدهای پردازش درخواست) به پرونده گزارش برنامه‌ی مربوطه هدایت شوند و در عین حال اطلاعات زمینه‌ای بیشتری مانند IP کلاینت، متد درخواست HTTP و نام کاربری کلاینت نیز در گزارش گنجانده شود؟

فرض کنید که کتابخانه را می‌توان با کد زیر شبیه‌سازی کرد:

# webapplib.py
import logging
import time

logger = logging.getLogger(__name__)

def useful():
    # Just a representative event logged from the library
    logger.debug('Hello from webapplib!')
    # Just sleep for a bit so other threads get to run
    time.sleep(0.01)

ما می‌توانیم چندین برنامه‌ی وب را به‌وسیله‌ی دو کلاس ساده، Request و WebApp شبیه‌سازی کنیم. این‌ها چگونگی کار برنامه‌های وب نخی واقعی را شبیه‌سازی می‌کنند - هر درخواست توسط یک نخ رسیدگی می‌شود:

# main.py
import argparse
from contextvars import ContextVar
import logging
import os
from random import choice
import threading
import webapplib

logger = logging.getLogger(__name__)
root = logging.getLogger()
root.setLevel(logging.DEBUG)

class Request:
    """
    A simple dummy request class which just holds dummy HTTP request method,
    client IP address and client username
    """
    def __init__(self, method, ip, user):
        self.method = method
        self.ip = ip
        self.user = user

# A dummy set of requests which will be used in the simulation - we'll just pick
# from this list randomly. Note that all GET requests are from 192.168.2.XXX
# addresses, whereas POST requests are from 192.16.3.XXX addresses. Three users
# are represented in the sample requests.

REQUESTS = [
    Request('GET', '192.168.2.20', 'jim'),
    Request('POST', '192.168.3.20', 'fred'),
    Request('GET', '192.168.2.21', 'sheila'),
    Request('POST', '192.168.3.21', 'jim'),
    Request('GET', '192.168.2.22', 'fred'),
    Request('POST', '192.168.3.22', 'sheila'),
]

# Note that the format string includes references to request context information
# such as HTTP method, client IP and username

formatter = logging.Formatter('%(threadName)-11s %(appName)s %(name)-9s %(user)-6s %(ip)s %(method)-4s %(message)s')

# Create our context variables. These will be filled at the start of request
# processing, and used in the logging that happens during that processing

ctx_request = ContextVar('request')
ctx_appname = ContextVar('appname')

class InjectingFilter(logging.Filter):
    """
    A filter which injects context-specific information into logs and ensures
    that only information for a specific webapp is included in its log
    """
    def __init__(self, app):
        self.app = app

    def filter(self, record):
        request = ctx_request.get()
        record.method = request.method
        record.ip = request.ip
        record.user = request.user
        record.appName = appName = ctx_appname.get()
        return appName == self.app.name

class WebApp:
    """
    A dummy web application class which has its own handler and filter for a
    webapp-specific log.
    """
    def __init__(self, name):
        self.name = name
        handler = logging.FileHandler(name + '.log', 'w')
        f = InjectingFilter(self)
        handler.setFormatter(formatter)
        handler.addFilter(f)
        root.addHandler(handler)
        self.num_requests = 0

    def process_request(self, request):
        """
        This is the dummy method for processing a request. It's called on a
        different thread for every request. We store the context information into
        the context vars before doing anything else.
        """
        ctx_request.set(request)
        ctx_appname.set(self.name)
        self.num_requests += 1
        logger.debug('Request processing started')
        webapplib.useful()
        logger.debug('Request processing finished')

def main():
    fn = os.path.splitext(os.path.basename(__file__))[0]
    adhf = argparse.ArgumentDefaultsHelpFormatter
    ap = argparse.ArgumentParser(formatter_class=adhf, prog=fn,
                                 description='Simulate a couple of web '
                                             'applications handling some '
                                             'requests, showing how request '
                                             'context can be used to '
                                             'populate logs')
    aa = ap.add_argument
    aa('--count', '-c', type=int, default=100, help='How many requests to simulate')
    options = ap.parse_args()

    # Create the dummy webapps and put them in a list which we can use to select
    # from randomly
    app1 = WebApp('app1')
    app2 = WebApp('app2')
    apps = [app1, app2]
    threads = []
    # Add a common handler which will capture all events
    handler = logging.FileHandler('app.log', 'w')
    handler.setFormatter(formatter)
    root.addHandler(handler)

    # Generate calls to process requests
    for i in range(options.count):
        try:
            # Pick an app at random and a request for it to process
            app = choice(apps)
            request = choice(REQUESTS)
            # Process the request in its own thread
            t = threading.Thread(target=app.process_request, args=(request,))
            threads.append(t)
            t.start()
        except KeyboardInterrupt:
            break

    # Wait for the threads to terminate
    for t in threads:
        t.join()

    for app in apps:
        print('%s processed %s requests' % (app.name, app.num_requests))

if __name__ == '__main__':
    main()

اگر مورد بالا را اجرا کنید، باید ببینید که تقریباً نیمی از درخواست‌ها به app1.log و بقیه به app2.log می‌روند و همه‌ی درخواست‌ها در app.log ثبت می‌شوند. هر گزارش مختص وب‌اپلیکیشن فقط شامل ورودی‌های گزارش همان وب‌اپلیکیشن خواهد بود و اطلاعات درخواست به‌صورت یکنواخت در گزارش نمایش داده خواهد شد (یعنی اطلاعات هر درخواست ساختگی همیشه با هم در یک خط گزارش ظاهر خواهد شد). این موضوع در خروجی پوسته‌ی زیر نشان داده شده است:

~/logging-contextual-webapp$ python main.py
app1 processed 51 requests
app2 processed 49 requests
~/logging-contextual-webapp$ wc -l *.log
  153 app1.log
  147 app2.log
  300 app.log
  600 total
~/logging-contextual-webapp$ head -3 app1.log
Thread-3 (process_request) app1 __main__  jim    192.168.3.21 POST Request processing started
Thread-3 (process_request) app1 webapplib jim    192.168.3.21 POST Hello from webapplib!
Thread-5 (process_request) app1 __main__  jim    192.168.3.21 POST Request processing started
~/logging-contextual-webapp$ head -3 app2.log
Thread-1 (process_request) app2 __main__  sheila 192.168.2.21 GET  Request processing started
Thread-1 (process_request) app2 webapplib sheila 192.168.2.21 GET  Hello from webapplib!
Thread-2 (process_request) app2 __main__  jim    192.168.2.20 GET  Request processing started
~/logging-contextual-webapp$ head app.log
Thread-1 (process_request) app2 __main__  sheila 192.168.2.21 GET  Request processing started
Thread-1 (process_request) app2 webapplib sheila 192.168.2.21 GET  Hello from webapplib!
Thread-2 (process_request) app2 __main__  jim    192.168.2.20 GET  Request processing started
Thread-3 (process_request) app1 __main__  jim    192.168.3.21 POST Request processing started
Thread-2 (process_request) app2 webapplib jim    192.168.2.20 GET  Hello from webapplib!
Thread-3 (process_request) app1 webapplib jim    192.168.3.21 POST Hello from webapplib!
Thread-4 (process_request) app2 __main__  fred   192.168.2.22 GET  Request processing started
Thread-5 (process_request) app1 __main__  jim    192.168.3.21 POST Request processing started
Thread-4 (process_request) app2 webapplib fred   192.168.2.22 GET  Hello from webapplib!
Thread-6 (process_request) app1 __main__  jim    192.168.3.21 POST Request processing started
~/logging-contextual-webapp$ grep app1 app1.log | wc -l
153
~/logging-contextual-webapp$ grep app2 app2.log | wc -l
147
~/logging-contextual-webapp$ grep app1 app.log | wc -l
153
~/logging-contextual-webapp$ grep app2 app.log | wc -l
147

انتقال اطلاعات زمینه‌ای در هندلرها

هر Handler زنجیره‌ای از فیلترهای خاص خود دارد. اگر می‌خواهید اطلاعات زمینه‌ای را به یک LogRecord اضافه کنید، بدون نشت این اطلاعات به سایر handlerها، می‌توانید از فیلتری استفاده کنید که به‌جای تغییر آن به‌صورت درجا، یک LogRecord جدید را برمی‌گرداند، همان‌طور که در اسکریپت زیر نشان داده شده است:

import copy
import logging

def filter(record: logging.LogRecord):
    record = copy.copy(record)
    record.user = 'jim'
    return record

if __name__ == '__main__':
    logger = logging.getLogger()
    logger.setLevel(logging.INFO)
    handler = logging.StreamHandler()
    formatter = logging.Formatter('%(message)s from %(user)-8s')
    handler.setFormatter(formatter)
    handler.addFilter(filter)
    logger.addHandler(handler)

    logger.info('A log message')

گزارش‌گیری در یک پرونده واحد از چندین فرآیند

اگرچه گزارش‌گیری ایمن نسبت به نخ است، و از گزارش‌گیری در یک پرونده واحد از چندین نخ در یک فرآیند واحد پشتیبانی می‌شود، اما از گزارش‌گیری در یک پرونده واحد از چندین فرآیند پشتیبانی نمی‌شود، زیرا هیچ روش استانداردی برای سریال‌سازی دسترسی به یک پرونده واحد در میان چندین فرآیند در پایتون وجود ندارد. اگر نیاز دارید وقایع را از چندین فرآیند در یک پرونده واحد ثبت کنید، یکی از راه‌های انجام این کار این است که همه فرآیندها وقایع را به یک SocketHandler ارسال کنند و فرآیند جداگانه‌ای وجود داشته باشد که یک سرور سوکت را پیاده‌سازی کند تا از سوکت بخواند و وقایع را در پرونده ثبت کند. (اگر ترجیح می‌دهید، می‌توانید یک نخ در یکی از فرآیندهای موجود را به انجام این وظیفه اختصاص دهید.) این بخش این روش را با جزئیات بیشتر مستند می‌کند و شامل یک گیرنده سوکت کاربردی است که می‌توانید از آن به‌عنوان نقطه شروعی برای تطبیق دادن در برنامه‌های خودتان استفاده کنید.

همچنین می‌توانید هندلر اختصاصی خودتان را بنویسید که از کلاس Lock در ماژول multiprocessing برای سریال‌سازی (serialize) دسترسی فرآیندهای شما به پرونده استفاده کند. FileHandler و زیرکلاس‌های آن در کتابخانه‌ی استاندارد از multiprocessing استفاده نمی‌کنند.

به‌عنوان جایگزین، می‌توانید از یک Queue و یک QueueHandler برای ارسال همه‌ی رویدادهای گزارش به یکی از فرایندهای برنامه‌ی چندفرایندی خود استفاده کنید. اسکریپت نمونه‌ی زیر نشان می‌دهد که چگونه می‌توانید این کار را انجام دهید؛ در این نمونه، یک فرایند شنونده‌ی جداگانه به رویدادهای ارسال‌شده توسط فرایندهای دیگر گوش می‌دهد و آن‌ها را مطابق پیکربندی گزارش خود ثبت می‌کند. اگرچه این نمونه تنها یک روش برای انجام این کار را نشان می‌دهد (برای مثال، ممکن است بخواهید به‌جای یک فرایند شنونده‌ی جداگانه از یک نخ شنونده استفاده کنید -- پیاده‌سازی آن مشابه خواهد بود)، اما امکان استفاده از پیکربندی‌های گزارش کاملاً متفاوت برای شنونده و سایر فرایندهای برنامه‌ی شما را فراهم می‌کند و می‌تواند به‌عنوان پایه‌ای برای کدی که نیازمندی‌های خاص شما را برآورده می‌کند استفاده شود:

# You'll need these imports in your own code
import logging
import logging.handlers
import multiprocessing

# Next two import lines for this demo only
from random import choice, random
import time

#
# Because you'll want to define the logging configurations for listener and workers, the
# listener and worker process functions take a configurer parameter which is a callable
# for configuring logging for that process. These functions are also passed the queue,
# which they use for communication.
#
# In practice, you can configure the listener however you want, but note that in this
# simple example, the listener does not apply level or filter logic to received records.
# In practice, you would probably want to do this logic in the worker processes, to avoid
# sending events which would be filtered out between processes.
#
# The size of the rotated files is made small so you can see the results easily.
def listener_configurer():
    root = logging.getLogger()
    h = logging.handlers.RotatingFileHandler('mptest.log', 'a', 300, 10)
    f = logging.Formatter('%(asctime)s %(processName)-10s %(name)s %(levelname)-8s %(message)s')
    h.setFormatter(f)
    root.addHandler(h)

# This is the listener process top-level loop: wait for logging events
# (LogRecords)on the queue and handle them, quit when you get a None for a
# LogRecord.
def listener_process(queue, configurer):
    configurer()
    while True:
        try:
            record = queue.get()
            if record is None:  # We send this as a sentinel to tell the listener to quit.
                break
            logger = logging.getLogger(record.name)
            logger.handle(record)  # No level or filter logic applied - just do it!
        except Exception:
            import sys, traceback
            print('Whoops! Problem:', file=sys.stderr)
            traceback.print_exc(file=sys.stderr)

# Arrays used for random selections in this demo

LEVELS = [logging.DEBUG, logging.INFO, logging.WARNING,
          logging.ERROR, logging.CRITICAL]

LOGGERS = ['a.b.c', 'd.e.f']

MESSAGES = [
    'Random message #1',
    'Random message #2',
    'Random message #3',
]

# The worker configuration is done at the start of the worker process run.
# Note that on Windows you can't rely on fork semantics, so each process
# will run the logging configuration code when it starts.
def worker_configurer(queue):
    h = logging.handlers.QueueHandler(queue)  # Just the one handler needed
    root = logging.getLogger()
    root.addHandler(h)
    # send all messages, for demo; no other level or filter logic applied.
    root.setLevel(logging.DEBUG)

# This is the worker process top-level loop, which just logs ten events with
# random intervening delays before terminating.
# The print messages are just so you know it's doing something!
def worker_process(queue, configurer):
    configurer(queue)
    name = multiprocessing.current_process().name
    print('Worker started: %s' % name)
    for i in range(10):
        time.sleep(random())
        logger = logging.getLogger(choice(LOGGERS))
        level = choice(LEVELS)
        message = choice(MESSAGES)
        logger.log(level, message)
    print('Worker finished: %s' % name)

# Here's where the demo gets orchestrated. Create the queue, create and start
# the listener, create ten workers and start them, wait for them to finish,
# then send a None to the queue to tell the listener to finish.
def main():
    queue = multiprocessing.Queue(-1)
    listener = multiprocessing.Process(target=listener_process,
                                       args=(queue, listener_configurer))
    listener.start()
    workers = []
    for i in range(10):
        worker = multiprocessing.Process(target=worker_process,
                                         args=(queue, worker_configurer))
        workers.append(worker)
        worker.start()
    for w in workers:
        w.join()
    queue.put_nowait(None)
    listener.join()

if __name__ == '__main__':
    main()

گونه‌ای از اسکریپت بالا، گزارش‌گیری را در فرایند اصلی و در نخی جداگانه نگه می‌دارد:

import logging
import logging.config
import logging.handlers
from multiprocessing import Process, Queue
import random
import threading
import time

def logger_thread(q):
    while True:
        record = q.get()
        if record is None:
            break
        logger = logging.getLogger(record.name)
        logger.handle(record)


def worker_process(q):
    qh = logging.handlers.QueueHandler(q)
    root = logging.getLogger()
    root.setLevel(logging.DEBUG)
    root.addHandler(qh)
    levels = [logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,
              logging.CRITICAL]
    loggers = ['foo', 'foo.bar', 'foo.bar.baz',
               'spam', 'spam.ham', 'spam.ham.eggs']
    for i in range(100):
        lvl = random.choice(levels)
        logger = logging.getLogger(random.choice(loggers))
        logger.log(lvl, 'Message no. %d', i)

if __name__ == '__main__':
    q = Queue()
    d = {
        'version': 1,
        'formatters': {
            'detailed': {
                'class': 'logging.Formatter',
                'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'
            }
        },
        'handlers': {
            'console': {
                'class': 'logging.StreamHandler',
                'level': 'INFO',
            },
            'file': {
                'class': 'logging.FileHandler',
                'filename': 'mplog.log',
                'mode': 'w',
                'formatter': 'detailed',
            },
            'foofile': {
                'class': 'logging.FileHandler',
                'filename': 'mplog-foo.log',
                'mode': 'w',
                'formatter': 'detailed',
            },
            'errors': {
                'class': 'logging.FileHandler',
                'filename': 'mplog-errors.log',
                'mode': 'w',
                'level': 'ERROR',
                'formatter': 'detailed',
            },
        },
        'loggers': {
            'foo': {
                'handlers': ['foofile']
            }
        },
        'root': {
            'level': 'DEBUG',
            'handlers': ['console', 'file', 'errors']
        },
    }
    workers = []
    for i in range(5):
        wp = Process(target=worker_process, name='worker %d' % (i + 1), args=(q,))
        workers.append(wp)
        wp.start()
    logging.config.dictConfig(d)
    lp = threading.Thread(target=logger_thread, args=(q,))
    lp.start()
    # At this point, the main process could do some useful work of its own
    # Once it's done that, it can wait for the workers to terminate...
    for wp in workers:
        wp.join()
    # And now tell the logging thread to finish up, too
    q.put(None)
    lp.join()

این گونه نشان می‌دهد که چگونه می‌توانید برای مثال پیکربندی را برای گزارش‌گیرهای خاص اعمال کنید؛ برای مثال، گزارش‌گیر foo یک هندلر ویژه دارد که همه رویدادهای زیرسیستم foo (subsystem) را در یک پرونده mplog-foo.log ذخیره می‌کند. این مورد توسط سازوکار گزارش‌گیری (logging machinery) در فرایند اصلی استفاده خواهد شد (اگرچه رویدادهای گزارش‌گیری در فرایندهای کارگر تولید می‌شوند) تا پیام‌ها را به مقصدهای مناسب هدایت کند.

استفاده از concurrent.futures.ProcessPoolExecutor

اگر می‌خواهید از concurrent.futures.ProcessPoolExecutor برای راه‌اندازی فرایندهای کارگر خود استفاده کنید، باید صف را به‌شکل کمی متفاوتی ایجاد کنید. به جای

queue = multiprocessing.Queue(-1)

شما باید استفاده کنید

queue = multiprocessing.Manager().Queue(-1)  # همچنین با مثال‌های بالا کار می‌کند

و سپس می‌توانید ایجادگر worker را از این بخش جایگزین کنید:

workers = []
for i in range(10):
    worker = multiprocessing.Process(target=worker_process,
                                     args=(queue, worker_configurer))
    workers.append(worker)
    worker.start()
for w in workers:
    w.join()

به این (به یاد داشته باشید که ابتدا concurrent.futures را ایمپورت کنید):

with concurrent.futures.ProcessPoolExecutor(max_workers=10) as executor:
    for i in range(10):
        executor.submit(worker_process, queue, worker_configurer)

استقرار برنامه‌های وب با استفاده از Gunicorn و uWSGI

هنگام استقرار برنامه‌های کاربردی وب با استفاده از Gunicorn یا uWSGI (یا مشابه آن‌ها)، چندین فرایند کارگر برای رسیدگی به درخواست‌های کلاینت ایجاد می‌شود. در چنین محیط‌هایی، از ایجاد هندلرهای مبتنی بر پرونده به‌صورت مستقیم در برنامه کاربردی وب خودداری کنید. در عوض، برای ارسال رویدادها از برنامه کاربردی وب به یک شنونده در یک فرایند جداگانه، از یک SocketHandler استفاده کنید. این کار را می‌توان با استفاده از یک ابزار مدیریت فرایند مانند Supervisor راه‌اندازی کرد؛ برای جزئیات بیشتر Running a logging socket listener in production را ببینید.

استفاده از چرخش پرونده

گاهی می‌خواهید اجازه دهید یک پرونده گزارش تا اندازه‌ای مشخص رشد کند، سپس پرونده جدیدی باز کنید و گزارش‌ها را در آن ثبت کنید. ممکن است بخواهید تعداد مشخصی از این پرونده‌ها را نگه دارید و وقتی آن تعداد پرونده ایجاد شده باشد، پرونده‌ها را بچرخانید تا هم تعداد پرونده‌ها و هم اندازه‌ی پرونده‌ها محدود باقی بمانند. برای این الگوی استفاده، بسته‌ی logging یک RotatingFileHandler ارائه می‌دهد:

import glob
import logging
import logging.handlers

LOG_FILENAME = 'logging_rotatingfile_example.out'

# Set up a specific logger with our desired output level
my_logger = logging.getLogger('MyLogger')
my_logger.setLevel(logging.DEBUG)

# Add the log message handler to the logger
handler = logging.handlers.RotatingFileHandler(
              LOG_FILENAME, maxBytes=20, backupCount=5)

my_logger.addHandler(handler)

# Log some messages
for i in range(20):
    my_logger.debug('i = %d' % i)

# See what files are created
logfiles = glob.glob('%s*' % LOG_FILENAME)

for filename in logfiles:
    print(filename)

نتیجه باید ۶ پرونده جداگانه باشد، که هرکدام بخشی از تاریخچه‌ی گزارش‌های برنامه را شامل می‌شوند:

logging_rotatingfile_example.out
logging_rotatingfile_example.out.1
logging_rotatingfile_example.out.2
logging_rotatingfile_example.out.3
logging_rotatingfile_example.out.4
logging_rotatingfile_example.out.5

پرونده جاری همیشه logging_rotatingfile_example.out است و هر بار که به محدودیت اندازه برسد، با پسوند .1 تغییر نام داده می‌شود. هر یک از پرونده‌های پشتیبان موجود برای افزایش پسوند تغییر نام داده می‌شوند (.1 به .2 تبدیل می‌شود، و غیره) و پرونده .6 حذف می‌شود.

بدیهی است که این مثال، طول گزارش را به‌عنوان یک مثال افراطی، بیش‌ازحد کوچک تنظیم می‌کند. بهتر است maxBytes را روی مقدار مناسبی تنظیم کنید.

استفاده از سبک‌های جایگزین قالب‌بندی

هنگامی که گزارش‌گیری به کتابخانه استاندارد پایتون اضافه شد، تنها راه قالب‌بندی پیام‌ها با محتوای متغیر، استفاده از روش قالب‌بندی درصدی (%-formatting) بود. از آن زمان، دو روش قالب‌بندی جدید به پایتون اضافه شده است: string.Template (در پایتون 2.4 اضافه شد) و str.format() (در پایتون 2.6 اضافه شد).

Logging (از نسخه‌ی 3.2) پشتیبانی بهتری برای این دو سبک قالب‌بندی اضافی فراهم می‌کند. کلاس Formatter بهبود یافته است تا یک پارامتر کلیدواژه‌ای اضافی و اختیاری به نام style بپذیرد. مقدار پیش‌فرض این پارامتر '%' است، اما مقادیر ممکن دیگر '{' و '$' هستند، که متناظر با دو سبک قالب‌بندی دیگر هستند. سازگاری با نسخه‌های پیشین به‌صورت پیش‌فرض حفظ می‌شود (همان‌طور که انتظار دارید)، اما با مشخص کردن صریح پارامتر style، می‌توانید رشته‌های قالبی را مشخص کنید که با str.format() یا string.Template کار می‌کنند. در ادامه یک نشست کنسول نمونه برای نشان دادن این امکانات آمده است:

>>> import logging
>>> root = logging.getLogger()
>>> root.setLevel(logging.DEBUG)
>>> handler = logging.StreamHandler()
>>> bf = logging.Formatter('{asctime} {name} {levelname:8s} {message}',
...                        style='{')
>>> handler.setFormatter(bf)
>>> root.addHandler(handler)
>>> logger = logging.getLogger('foo.bar')
>>> logger.debug('This is a DEBUG message')
2010-10-28 15:11:55,341 foo.bar DEBUG    This is a DEBUG message
>>> logger.critical('This is a CRITICAL message')
2010-10-28 15:12:11,526 foo.bar CRITICAL This is a CRITICAL message
>>> df = logging.Formatter('$asctime $name ${levelname} $message',
...                        style='$')
>>> handler.setFormatter(df)
>>> logger.debug('This is a DEBUG message')
2010-10-28 15:13:06,924 foo.bar DEBUG This is a DEBUG message
>>> logger.critical('This is a CRITICAL message')
2010-10-28 15:13:11,494 foo.bar CRITICAL This is a CRITICAL message
>>>

توجه داشته باشید که قالب‌بندی پیام‌های گزارش برای خروجی نهایی به گزارش‌ها، کاملاً مستقل از چگونگی ساخت یک پیام گزارش منفرد است. برای ساخت آن هنوز می‌توان از قالب‌بندی %- (%-formatting) استفاده کرد، همان‌طور که در اینجا نشان داده شده است:

>>> logger.error('This is an%s %s %s', 'other,', 'ERROR,', 'message')
2010-10-28 15:19:29,833 foo.bar ERROR This is another, ERROR, message
>>>

فراخوانی‌های گزارش‌گیری (logger.debug()، logger.info() و غیره) فقط پارامترهای جایگاهی برای خود پیام گزارش‌گیری واقعی می‌پذیرند، و پارامترهای کلیدواژه‌ای فقط برای تعیین گزینه‌هایی درباره‌ی نحوه‌ی مدیریت فراخوانی گزارش‌گیری واقعی به کار می‌روند (برای مثال، پارامتر کلیدواژه‌ای exc_info برای نشان دادن اینکه اطلاعات ردگیری پشته باید ثبت شود، یا پارامتر کلیدواژه‌ای extra برای نشان دادن اطلاعات زمینه‌ای اضافی که باید به گزارش اضافه شود). بنابراین نمی‌توانید به‌طور مستقیم فراخوانی‌های گزارش‌گیری را با سینتکس str.format() یا string.Template انجام دهید، زیرا بسته‌ی logging به‌صورت داخلی از %-formatting برای ادغام رشته‌ی قالب و آرگومان‌های متغیر استفاده می‌کند. در عین حفظ سازگاری با عقب‌گرد، امکان تغییر این موضوع وجود نخواهد داشت، زیرا همه‌ی فراخوانی‌های گزارش‌گیری موجود در کدهای موجود از رشته‌های %-format استفاده خواهند کرد.

با این حال، راهی وجود دارد که می‌توانید از قالب‌بندی {} و $ برای ساخت پیام‌های گزارش جداگانه‌ی خود استفاده کنید. به یاد داشته باشید که برای یک پیام می‌توانید از یک شیء دلخواه به‌عنوان رشته‌ی قالب پیام استفاده کنید، و بسته‌ی logging str() را روی آن شیء فراخوانی می‌کند تا رشته‌ی قالب واقعی را به دست آورد. دو کلاس زیر را در نظر بگیرید:

class BraceMessage:
    def __init__(self, fmt, /, *args, **kwargs):
        self.fmt = fmt
        self.args = args
        self.kwargs = kwargs

    def __str__(self):
        return self.fmt.format(*self.args, **self.kwargs)

class DollarMessage:
    def __init__(self, fmt, /, **kwargs):
        self.fmt = fmt
        self.kwargs = kwargs

    def __str__(self):
        from string import Template
        return Template(self.fmt).substitute(**self.kwargs)

هر یک از این‌ها می‌توانند به‌جای یک رشته‌قالب استفاده شوند، تا بتوان از قالب‌بندی {} یا $ برای ساخت بخش «پیام» واقعی استفاده کرد؛ بخشی که در خروجی گزارش قالب‌بندی‌شده به‌جای "%(message)s" یا "{message}" یا "$message" ظاهر می‌شود. استفاده از نام کلاس‌ها هر بار که بخواهید چیزی را گزارش کنید کمی دست‌وپاگیر است، اما اگر از نام مستعاری مانند __ (دو زیرخط --- نباید با _، زیرخط تکی که به‌عنوان مترادف/نام مستعار برای gettext.gettext() یا هم‌خانواده‌های آن استفاده می‌شود، اشتباه گرفته شود) استفاده کنید، کاملاً قابل‌قبول است.

کلاس‌های بالا در پایتون گنجانده نشده‌اند، هرچند کپی و پیست کردن آن‌ها در کد خودتان به‌اندازه کافی آسان است. می‌توان از آن‌ها به‌صورت زیر استفاده کرد (با فرض اینکه در ماژولی به نام wherever تعریف شده‌اند):

>>> from wherever import BraceMessage as __
>>> print(__('Message with {0} {name}', 2, name='placeholders'))
Message with 2 placeholders
>>> class Point: pass
...
>>> p = Point()
>>> p.x = 0.5
>>> p.y = 0.5
>>> print(__('Message with coordinates: ({point.x:.2f}, {point.y:.2f})',
...       point=p))
Message with coordinates: (0.50, 0.50)
>>> from wherever import DollarMessage as __
>>> print(__('Message with $num $what', num=2, what='placeholders'))
Message with 2 placeholders
>>>

هرچند مثال‌های بالا از print() برای نشان دادن چگونگی کارکرد قالب‌بندی استفاده می‌کنند، البته برای گزارش کردن واقعی با این روش از logger.debug() یا مشابه آن استفاده خواهید کرد.

نکته‌ای که باید به آن توجه داشته باشید این است که با این رویکرد، شما هیچ هزینه‌ی عملکردی قابل‌توجهی متحمل نمی‌شوید: قالب‌بندی واقعی نه هنگامی اتفاق می‌افتد که فراخوانی logging را انجام می‌دهید، بلکه هنگامی (و اگر) پیام گزارش‌شده واقعاً در آستانه‌ی آن باشد که توسط یک هندلر به یک گزارش خروجی داده شود. بنابراین، تنها نکته‌ی کمی غیرمعمول که ممکن است شما را به اشتباه بیندازد این است که پرانتزها در اطراف رشته‌ی قالب و آرگومان‌ها قرار می‌گیرند، نه فقط رشته‌ی قالب. این به این دلیل است که نمادگذاری __ صرفاً قند نحوی برای فراخوانی سازنده‌ی یکی از کلاس‌های XXXMessage است.

در صورت تمایل، می‌توانید از یک LoggerAdapter برای دستیابی به نتیجه‌ای مشابه مورد بالا استفاده کنید، همان‌طور که در مثال زیر آمده است:

import logging

class Message:
    def __init__(self, fmt, args):
        self.fmt = fmt
        self.args = args

    def __str__(self):
        return self.fmt.format(*self.args)

class StyleAdapter(logging.LoggerAdapter):
    def log(self, level, msg, /, *args, stacklevel=1, **kwargs):
        if self.isEnabledFor(level):
            msg, kwargs = self.process(msg, kwargs)
            self.logger.log(level, Message(msg, args), **kwargs,
                            stacklevel=stacklevel+1)

logger = StyleAdapter(logging.getLogger(__name__))

def main():
    logger.debug('Hello, {}', 'world!')

if __name__ == '__main__':
    logging.basicConfig(level=logging.DEBUG)
    main()

اسکریپت بالا باید هنگام اجرا با پایتون 3.8 یا بالاتر، پیام Hello, world! را ثبت کند.

سفارشی‌سازی LogRecord

هر رویداد گزارش‌گیری با یک نمونه از LogRecord بازنمایی می‌شود. هنگامی که رویدادی ثبت می‌شود و توسط سطح گزارش‌گیر فیلتر نمی‌شود، یک LogRecord ایجاد می‌شود، با اطلاعات مربوط به رویداد پر می‌شود و سپس به هندلرهای آن گزارش‌گیر (و گزارش‌گیرهای بالادستی آن، تا و شامل گزارش‌گیری که انتشار بیشتر به سمت بالای سلسله‌مراتب در آن غیرفعال شده است) ارسال می‌شود. پیش از پایتون 3.2، تنها دو مکان وجود داشت که این ایجاد در آن‌ها صورت می‌گرفت:

• Logger.makeRecord()، که در فرآیند عادی ثبت یک رویداد فراخوانی می‌شود. این متد LogRecord را به‌طور مستقیم برای ایجاد یک نمونه فراخوانی می‌کند.

• makeLogRecord()، که با یک دیکشنری حاوی ویژگی‌هایی فراخوانی می‌شود که باید به LogRecord افزوده شوند. این معمولاً زمانی فراخوانی می‌شود که یک دیکشنری مناسب از طریق شبکه دریافت شده باشد (برای مثال در قالب pickle از طریق یک SocketHandler، یا در قالب JSON از طریق یک HTTPHandler).

این معمولاً به این معنا بوده است که اگر نیاز داشته باشید کار خاصی با یک LogRecord انجام دهید، مجبور بوده‌اید یکی از موارد زیر را انجام دهید.

• زیرکلاس اختصاصی خود از Logger را بسازید که Logger.makeRecord() را بازنویسی می‌کند، و آن را پیش از نمونه‌سازی هر گزارش‌گیری که برایتان اهمیت دارد، با استفاده از setLoggerClass() تنظیم کنید.

• یک Filter را به یک گزارش‌گیر یا هندلر اضافه کنید، که دستکاری خاص مورد نیاز شما را هنگام فراخوانی متد filter() آن انجام می‌دهد.

رویکرد اول در سناریویی که (مثلاً) چند کتابخانه‌ی مختلف بخواهند کارهای متفاوتی انجام دهند، کمی دست‌وپاگیر خواهد بود. هرکدام تلاش می‌کند زیرکلاس Logger خود را تنظیم کند، و آخرین موردی که این کار را انجام دهد برنده می‌شود.

رویکرد دوم برای بسیاری از موارد نسبتاً خوب کار می‌کند، اما به شما اجازه نمی‌دهد که برای مثال از یک زیرکلاس تخصصی از LogRecord استفاده کنید. توسعه‌دهندگان کتابخانه می‌توانند فیلتر مناسبی را روی گزارش‌گیرهای خود تنظیم کنند، اما باید به یاد داشته باشند که هر بار که گزارش‌گیر جدیدی معرفی می‌کنند، این کار را انجام دهند (که این کار را صرفاً با افزودن بسته‌ها یا ماژول‌های جدید و انجام دادن

logger = logging.getLogger(__name__)

در سطح ماژول). این احتمالاً یک مورد اضافی برای فکر کردن است. توسعه‌دهندگان همچنین می‌توانند فیلتر را به یک NullHandler متصل به گزارش‌گیر سطح بالای خود اضافه کنند، اما اگر توسعه‌دهنده‌ی برنامه یک هندلر را به یک گزارش‌گیر کتابخانه در سطح پایین‌تر متصل کند، این فیلتر فراخوانی نمی‌شود—بنابراین خروجی آن هندلر، نیات توسعه‌دهنده‌ی کتابخانه را بازتاب نمی‌دهد.

در پایتون 3.2 و نسخه‌های بعدی، ایجاد LogRecord از طریق یک کارخانه انجام می‌شود که شما می‌توانید آن را تعیین کنید. کارخانه فقط یک شیء فراخوانی‌پذیر است که می‌توانید آن را با setLogRecordFactory() تنظیم کنید و با getLogRecordFactory() بازخوانی کنید. کارخانه با همان امضای سازنده‌ی LogRecord فراخوانی می‌شود، زیرا LogRecord تنظیم پیش‌فرض برای کارخانه است.

این رویکرد به یک کارخانه سفارشی اجازه می‌دهد تا تمام جنبه‌های ایجاد LogRecord را کنترل کند. برای مثال، می‌توانید یک زیرکلاس را برگردانید، یا صرفاً چند ویژگی اضافی را پس از ایجاد، به رکورد اضافه کنید؛ با استفاده از الگویی مشابه این:

old_factory = logging.getLogRecordFactory()

def record_factory(*args, **kwargs):
    record = old_factory(*args, **kwargs)
    record.custom_attribute = 0xdecafbad
    return record

logging.setLogRecordFactory(record_factory)

این الگو به کتابخانه‌های مختلف اجازه می‌دهد کارخانه‌ها را به‌صورت زنجیره‌ای به هم متصل کنند، و تا زمانی که ویژگی‌های یکدیگر را بازنویسی نکنند یا ویژگی‌های ارائه‌شده به‌عنوان استاندارد را به‌طور غیرعمدی بازنویسی نکنند، نباید مورد غیرمنتظره‌ای پیش بیاید. با این حال، باید توجه داشت که هر پیوند در زنجیره به تمام عملیات گزارش‌گیری سربار ران‌تایم اضافه می‌کند، و این تکنیک فقط زمانی باید استفاده شود که استفاده از یک Filter نتیجه دلخواه را فراهم نکند.

زیرکلاس‌سازی از QueueHandler و QueueListener — نمونه‌ای با ZeroMQ

زیرکلاس QueueHandler

شما می‌توانید از زیرکلاسی از QueueHandler برای ارسال پیام‌ها به انواع دیگر صف‌ها استفاده کنید، برای مثال یک سوکت 'publish' از ZeroMQ. در مثال زیر، سوکت به‌صورت جداگانه ایجاد می‌شود و به هندلر (به‌عنوان 'queue' آن) داده می‌شود:

import zmq   # using pyzmq, the Python binding for ZeroMQ
import json  # for serializing records portably

ctx = zmq.Context()
sock = zmq.Socket(ctx, zmq.PUB)  # or zmq.PUSH, or other suitable value
sock.bind('tcp://*:5556')        # or wherever

class ZeroMQSocketHandler(QueueHandler):
    def enqueue(self, record):
        self.queue.send_json(record.__dict__)


handler = ZeroMQSocketHandler(sock)

البته راه‌های دیگری برای سازمان‌دهی این کار وجود دارد، برای مثال، ارسال داده‌های مورد نیاز هندلر برای ایجاد سوکت:

class ZeroMQSocketHandler(QueueHandler):
    def __init__(self, uri, socktype=zmq.PUB, ctx=None):
        self.ctx = ctx or zmq.Context()
        socket = zmq.Socket(self.ctx, socktype)
        socket.bind(uri)
        super().__init__(socket)

    def enqueue(self, record):
        self.queue.send_json(record.__dict__)

    def close(self):
        self.queue.close()

زیرکلاس QueueListener

همچنین می‌توانید QueueListener را زیرکلاس‌سازی کنید تا پیام‌ها را از انواع دیگر صف‌ها دریافت کنید، برای مثال از یک سوکت 'subscribe' در ZeroMQ. در اینجا یک مثال آمده است:

class ZeroMQSocketListener(QueueListener):
    def __init__(self, uri, /, *handlers, **kwargs):
        self.ctx = kwargs.get('ctx') or zmq.Context()
        socket = zmq.Socket(self.ctx, zmq.SUB)
        socket.setsockopt_string(zmq.SUBSCRIBE, '')  # subscribe to everything
        socket.connect(uri)
        super().__init__(socket, *handlers, **kwargs)

    def dequeue(self):
        msg = self.queue.recv_json()
        return logging.makeLogRecord(msg)

زیرکلاس‌سازی از QueueHandler و QueueListener - یک مثال pynng

به شیوه‌ای مشابه بخش بالا، می‌توانیم یک شنونده و هندلر با استفاده از pynng پیاده‌سازی کنیم، که یک اتصال پایتون به NNG است و به‌عنوان جانشین معنوی ZeroMQ معرفی می‌شود. قطعه‌کدهای زیر این موضوع را نشان می‌دهند — می‌توانید آن‌ها را در محیطی که pynng در آن نصب شده است آزمایش کنید. فقط برای تنوع، ابتدا شنونده را ارائه می‌کنیم.

زیرکلاس QueueListener

# listener.py
import json
import logging
import logging.handlers

import pynng

DEFAULT_ADDR = "tcp://localhost:13232"

interrupted = False

class NNGSocketListener(logging.handlers.QueueListener):

    def __init__(self, uri, /, *handlers, **kwargs):
        # Have a timeout for interruptibility, and open a
        # subscriber socket
        socket = pynng.Sub0(listen=uri, recv_timeout=500)
        # The b'' subscription matches all topics
        topics = kwargs.pop('topics', None) or b''
        socket.subscribe(topics)
        # We treat the socket as a queue
        super().__init__(socket, *handlers, **kwargs)

    def dequeue(self, block):
        data = None
        # Keep looping while not interrupted and no data received over the
        # socket
        while not interrupted:
            try:
                data = self.queue.recv(block=block)
                break
            except pynng.Timeout:
                pass
            except pynng.Closed:  # sometimes happens when you hit Ctrl-C
                break
        if data is None:
            return None
        # Get the logging event sent from a publisher
        event = json.loads(data.decode('utf-8'))
        return logging.makeLogRecord(event)

    def enqueue_sentinel(self):
        # Not used in this implementation, as the socket isn't really a
        # queue
        pass

logging.getLogger('pynng').propagate = False
listener = NNGSocketListener(DEFAULT_ADDR, logging.StreamHandler(), topics=b'')
listener.start()
print('Press Ctrl-C to stop.')
try:
    while True:
        pass
except KeyboardInterrupt:
    interrupted = True
finally:
    listener.stop()

زیرکلاس QueueHandler

# sender.py
import json
import logging
import logging.handlers
import time
import random

import pynng

DEFAULT_ADDR = "tcp://localhost:13232"

class NNGSocketHandler(logging.handlers.QueueHandler):

    def __init__(self, uri):
        socket = pynng.Pub0(dial=uri, send_timeout=500)
        super().__init__(socket)

    def enqueue(self, record):
        # Send the record as UTF-8 encoded JSON
        d = dict(record.__dict__)
        data = json.dumps(d)
        self.queue.send(data.encode('utf-8'))

    def close(self):
        self.queue.close()

logging.getLogger('pynng').propagate = False
handler = NNGSocketHandler(DEFAULT_ADDR)
# Make sure the process ID is in the output
logging.basicConfig(level=logging.DEBUG,
                    handlers=[logging.StreamHandler(), handler],
                    format='%(levelname)-8s %(name)10s %(process)6s %(message)s')
levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,
          logging.CRITICAL)
logger_names = ('myapp', 'myapp.lib1', 'myapp.lib2')
msgno = 1
while True:
    # Just randomly select some loggers and levels and log away
    level = random.choice(levels)
    logger = logging.getLogger(random.choice(logger_names))
    logger.log(level, 'Message no. %5d' % msgno)
    msgno += 1
    delay = random.random() * 2 + 0.5
    time.sleep(delay)

شما می‌توانید دو قطعه‌کد بالا را در پوسته‌های خط فرمان جداگانه اجرا کنید. اگر شنونده را در یک پوسته و فرستنده را در دو پوسته جداگانه اجرا کنید، باید چیزی شبیه به زیر ببینید. در اولین پوسته فرستنده:

$ python sender.py
DEBUG         myapp    613 Message no.     1
WARNING  myapp.lib2    613 Message no.     2
CRITICAL myapp.lib2    613 Message no.     3
WARNING  myapp.lib2    613 Message no.     4
CRITICAL myapp.lib1    613 Message no.     5
DEBUG         myapp    613 Message no.     6
CRITICAL myapp.lib1    613 Message no.     7
INFO     myapp.lib1    613 Message no.     8
(و به همین ترتیب)

در دومین پوسته‌ی فرستنده:

$ python sender.py
INFO     myapp.lib2    657 Message no.     1
CRITICAL myapp.lib2    657 Message no.     2
CRITICAL      myapp    657 Message no.     3
CRITICAL myapp.lib1    657 Message no.     4
INFO     myapp.lib1    657 Message no.     5
WARNING  myapp.lib2    657 Message no.     6
CRITICAL      myapp    657 Message no.     7
DEBUG    myapp.lib1    657 Message no.     8
(و غیره)

در پوسته‌ی شنونده:

$ python listener.py
Press Ctrl-C to stop.
DEBUG         myapp    613 Message no.     1
WARNING  myapp.lib2    613 Message no.     2
INFO     myapp.lib2    657 Message no.     1
CRITICAL myapp.lib2    613 Message no.     3
CRITICAL myapp.lib2    657 Message no.     2
CRITICAL      myapp    657 Message no.     3
WARNING  myapp.lib2    613 Message no.     4
CRITICAL myapp.lib1    613 Message no.     5
CRITICAL myapp.lib1    657 Message no.     4
INFO     myapp.lib1    657 Message no.     5
DEBUG         myapp    613 Message no.     6
WARNING  myapp.lib2    657 Message no.     6
CRITICAL      myapp    657 Message no.     7
CRITICAL myapp.lib1    613 Message no.     7
INFO     myapp.lib1    613 Message no.     8
DEBUG    myapp.lib1    657 Message no.     8
(and so on)

همان‌طور که می‌بینید، گزارش‌های دو فرآیند فرستنده در خروجی شنونده درهم‌آمیخته شده‌اند.

یک نمونه پیکربندی مبتنی بر دیکشنری

در زیر نمونه‌ای از یک دیکشنری پیکربندی گزارش آمده است؛ این نمونه از مستندات پروژه جنگو گرفته شده است. این دیکشنری به dictConfig() ارسال می‌شود تا پیکربندی اعمال شود:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'verbose': {
            'format': '{levelname} {asctime} {module} {process:d} {thread:d} {message}',
            'style': '{',
        },
        'simple': {
            'format': '{levelname} {message}',
            'style': '{',
        },
    },
    'filters': {
        'special': {
            '()': 'project.logging.SpecialFilter',
            'foo': 'bar',
        },
    },
    'handlers': {
        'console': {
            'level': 'INFO',
            'class': 'logging.StreamHandler',
            'formatter': 'simple',
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
            'filters': ['special']
        }
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'propagate': True,
        },
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': False,
        },
        'myproject.custom': {
            'handlers': ['console', 'mail_admins'],
            'level': 'INFO',
            'filters': ['special']
        }
    }
}

برای اطلاعات بیشتر درباره این پیکربندی، می‌توانید بخش مربوطه را در مستندات جنگو مشاهده کنید.

استفاده از چرخاننده (rotator) و نام‌گذار (namer) برای سفارشی‌سازی پردازش چرخش گزارش

مثالی از چگونگی تعریف یک نام‌گذار (namer) و چرخاننده (rotator) در اسکریپت قابل‌اجرای زیر ارائه شده است که فشرده‌سازی پرونده گزارش با gzip را نشان می‌دهد:

import gzip
import logging
import logging.handlers
import os
import shutil

def namer(name):
    return name + ".gz"

def rotator(source, dest):
    with open(source, 'rb') as f_in:
        with gzip.open(dest, 'wb') as f_out:
            shutil.copyfileobj(f_in, f_out)
    os.remove(source)


rh = logging.handlers.RotatingFileHandler('rotated.log', maxBytes=128, backupCount=5)
rh.rotator = rotator
rh.namer = namer

root = logging.getLogger()
root.setLevel(logging.INFO)
root.addHandler(rh)
f = logging.Formatter('%(asctime)s %(message)s')
rh.setFormatter(f)
for i in range(1000):
    root.info(f'Message no. {i + 1}')

پس از اجرای این، ۶ پرونده جدید خواهید دید که ۵ مورد از آن‌ها فشرده هستند:

$ ls rotated.log*
rotated.log       rotated.log.2.gz  rotated.log.4.gz
rotated.log.1.gz  rotated.log.3.gz  rotated.log.5.gz
$ zcat rotated.log.1.gz
2023-01-20 02:28:17,767 Message no. 996
2023-01-20 02:28:17,767 Message no. 997
2023-01-20 02:28:17,767 Message no. 998

نمونه‌ای مفصل‌تر از چندپردازشی

مثال عملی زیر نشان می‌دهد که چگونه می‌توان از گزارش‌گیری همراه با چندپردازشی (multiprocessing) و با استفاده از پرونده‌های پیکربندی استفاده کرد. این پیکربندی‌ها نسبتاً ساده هستند، اما نشان می‌دهند که چگونه می‌توان پیکربندی‌های پیچیده‌تر را در یک سناریوی واقعی چندپردازشی پیاده‌سازی کرد.

در این مثال، فرایند اصلی یک فرایند شنونده و چند فرایند کارگر را ایجاد می‌کند. فرایند اصلی، شنونده و کارگرها سه پیکربندی جداگانه دارند (همه‌ی کارگرها پیکربندی یکسانی دارند). می‌توانیم گزارش کردن در فرایند اصلی را ببینیم، این‌که کارگرها چگونه به یک QueueHandler گزارش می‌فرستند و شنونده چگونه یک QueueListener و یک پیکربندی گزارش پیچیده‌تر را پیاده‌سازی می‌کند و ترتیبی می‌دهد که رویدادهای دریافت‌شده از طریق صف به هندلرهای مشخص‌شده در پیکربندی ارسال شوند. توجه داشته باشید که این پیکربندی‌ها صرفاً جنبه‌ی توضیحی دارند، اما باید بتوانید این مثال را با سناریوی خودتان تطبیق دهید.

این هم اسکریپت - امید است رشته مستندها و کامنت‌ها چگونگی کارکرد آن را توضیح دهند:

import logging
import logging.config
import logging.handlers
from multiprocessing import Process, Queue, Event, current_process
import os
import random
import time

class MyHandler:
    """
    A simple handler for logging events. It runs in the listener process and
    dispatches events to loggers based on the name in the received record,
    which then get dispatched, by the logging system, to the handlers
    configured for those loggers.
    """

    def handle(self, record):
        if record.name == "root":
            logger = logging.getLogger()
        else:
            logger = logging.getLogger(record.name)

        if logger.isEnabledFor(record.levelno):
            # The process name is transformed just to show that it's the listener
            # doing the logging to files and console
            record.processName = '%s (for %s)' % (current_process().name, record.processName)
            logger.handle(record)

def listener_process(q, stop_event, config):
    """
    This could be done in the main process, but is just done in a separate
    process for illustrative purposes.

    This initialises logging according to the specified configuration,
    starts the listener and waits for the main process to signal completion
    via the event. The listener is then stopped, and the process exits.
    """
    logging.config.dictConfig(config)
    listener = logging.handlers.QueueListener(q, MyHandler())
    listener.start()
    if os.name == 'posix':
        # On POSIX, the setup logger will have been configured in the
        # parent process, but should have been disabled following the
        # dictConfig call.
        # On Windows, since fork isn't used, the setup logger won't
        # exist in the child, so it would be created and the message
        # would appear - hence the "if posix" clause.
        logger = logging.getLogger('setup')
        logger.critical('Should not appear, because of disabled logger ...')
    stop_event.wait()
    listener.stop()

def worker_process(config):
    """
    A number of these are spawned for the purpose of illustration. In
    practice, they could be a heterogeneous bunch of processes rather than
    ones which are identical to each other.

    This initialises logging according to the specified configuration,
    and logs a hundred messages with random levels to randomly selected
    loggers.

    A small sleep is added to allow other processes a chance to run. This
    is not strictly needed, but it mixes the output from the different
    processes a bit more than if it's left out.
    """
    logging.config.dictConfig(config)
    levels = [logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,
              logging.CRITICAL]
    loggers = ['foo', 'foo.bar', 'foo.bar.baz',
               'spam', 'spam.ham', 'spam.ham.eggs']
    if os.name == 'posix':
        # On POSIX, the setup logger will have been configured in the
        # parent process, but should have been disabled following the
        # dictConfig call.
        # On Windows, since fork isn't used, the setup logger won't
        # exist in the child, so it would be created and the message
        # would appear - hence the "if posix" clause.
        logger = logging.getLogger('setup')
        logger.critical('Should not appear, because of disabled logger ...')
    for i in range(100):
        lvl = random.choice(levels)
        logger = logging.getLogger(random.choice(loggers))
        logger.log(lvl, 'Message no. %d', i)
        time.sleep(0.01)

def main():
    q = Queue()
    # The main process gets a simple configuration which prints to the console.
    config_initial = {
        'version': 1,
        'handlers': {
            'console': {
                'class': 'logging.StreamHandler',
                'level': 'INFO'
            }
        },
        'root': {
            'handlers': ['console'],
            'level': 'DEBUG'
        }
    }
    # The worker process configuration is just a QueueHandler attached to the
    # root logger, which allows all messages to be sent to the queue.
    # We disable existing loggers to disable the "setup" logger used in the
    # parent process. This is needed on POSIX because the logger will
    # be there in the child following a fork().
    config_worker = {
        'version': 1,
        'disable_existing_loggers': True,
        'handlers': {
            'queue': {
                'class': 'logging.handlers.QueueHandler',
                'queue': q
            }
        },
        'root': {
            'handlers': ['queue'],
            'level': 'DEBUG'
        }
    }
    # The listener process configuration shows that the full flexibility of
    # logging configuration is available to dispatch events to handlers however
    # you want.
    # We disable existing loggers to disable the "setup" logger used in the
    # parent process. This is needed on POSIX because the logger will
    # be there in the child following a fork().
    config_listener = {
        'version': 1,
        'disable_existing_loggers': True,
        'formatters': {
            'detailed': {
                'class': 'logging.Formatter',
                'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'
            },
            'simple': {
                'class': 'logging.Formatter',
                'format': '%(name)-15s %(levelname)-8s %(processName)-10s %(message)s'
            }
        },
        'handlers': {
            'console': {
                'class': 'logging.StreamHandler',
                'formatter': 'simple',
                'level': 'INFO'
            },
            'file': {
                'class': 'logging.FileHandler',
                'filename': 'mplog.log',
                'mode': 'w',
                'formatter': 'detailed'
            },
            'foofile': {
                'class': 'logging.FileHandler',
                'filename': 'mplog-foo.log',
                'mode': 'w',
                'formatter': 'detailed'
            },
            'errors': {
                'class': 'logging.FileHandler',
                'filename': 'mplog-errors.log',
                'mode': 'w',
                'formatter': 'detailed',
                'level': 'ERROR'
            }
        },
        'loggers': {
            'foo': {
                'handlers': ['foofile']
            }
        },
        'root': {
            'handlers': ['console', 'file', 'errors'],
            'level': 'DEBUG'
        }
    }
    # Log some initial events, just to show that logging in the parent works
    # normally.
    logging.config.dictConfig(config_initial)
    logger = logging.getLogger('setup')
    logger.info('About to create workers ...')
    workers = []
    for i in range(5):
        wp = Process(target=worker_process, name='worker %d' % (i + 1),
                     args=(config_worker,))
        workers.append(wp)
        wp.start()
        logger.info('Started worker: %s', wp.name)
    logger.info('About to create listener ...')
    stop_event = Event()
    lp = Process(target=listener_process, name='listener',
                 args=(q, stop_event, config_listener))
    lp.start()
    logger.info('Started listener')
    # We now hang around for the workers to finish their work.
    for wp in workers:
        wp.join()
    # Workers all done, listening can now stop.
    # Logging in the parent still works normally.
    logger.info('Telling listener to stop ...')
    stop_event.set()
    lp.join()
    logger.info('All done.')

if __name__ == '__main__':
    main()

درج BOM در پیام‌های ارسالی به SysLogHandler

RFC 5424 الزام می‌کند که یک پیام یونیکدی به‌صورت مجموعه‌ای از بایت‌ها با ساختار زیر به دیمن syslog ارسال شود: یک کامپوننت اختیاری ASCII خالص، پس از آن یک نشانگر ترتیب بایت UTF-8 (BOM)، و پس از آن یونیکد کدگذاری‌شده با UTF-8. (به بخش مرتبط از مشخصات مراجعه کنید.)

در پایتون 3.1، کدی به SysLogHandler اضافه شد تا یک BOM را در پیام درج کند، اما متأسفانه پیاده‌سازی آن نادرست بود، به‌طوری که BOM در ابتدای پیام قرار می‌گرفت و بنابراین اجازه نمی‌داد هیچ کامپوننت ASCII خالصی پیش از آن قرار بگیرد.

از آن‌جا که این رفتار معیوب است، کد درج نادرست BOM از Python 3.2.4 و نسخه‌های بعدی حذف می‌شود. با این حال، جایگزینی برای آن در نظر گرفته نمی‌شود، و اگر می‌خواهید پیام‌هایی مطابق RFC 5424 تولید کنید که شامل یک BOM، یک دنباله‌ی اختیاری ASCII خالص پیش از آن و یونیکد دلخواه پس از آن باشند و با UTF-8 کدگذاری شده باشند، باید کارهای زیر را انجام دهید:

1. نمونه‌ای از Formatter را به نمونه‌ای از SysLogHandler خود متصل کنید، با رشته قالبی مانند:

   بخش ASCIIبخش یونیکد
   

   نقطه‌کد یونیکد U+FEFF، هنگام کدگذاری با UTF-8، به‌صورت UTF-8 BOM کدگذاری خواهد شد — رشته‌بایت b'\xef\xbb\xbf'.

2. بخش ASCII را با هر جای‌نگهدار دلخواهی جایگزین کنید، اما اطمینان حاصل کنید که داده‌ای که پس از جایگزینی در آنجا ظاهر می‌شود، همیشه ASCII باشد (به این ترتیب، پس از کدگذاری UTF-8 بدون تغییر باقی خواهد ماند).

3. بخش یونیکد را با هر جانگهداری که می‌خواهید جایگزین کنید؛ اگر داده‌ای که پس از جایگزینی در آنجا ظاهر می‌شود شامل نویسه‌هایی خارج از محدوده‌ی ASCII باشد، اشکالی ندارد -- با استفاده از UTF-8 کدگذاری خواهد شد.

پیام قالب‌بندی‌شده با استفاده از کدگذاری UTF-8 توسط SysLogHandler کدگذاری خواهد شد. اگر قواعد بالا را دنبال کنید، باید بتوانید پیام‌های سازگار با RFC 5424 تولید کنید. اگر این کار را نکنید، ممکن است logging شکایتی نکند، اما پیام‌های شما با RFC 5424 سازگار نخواهند بود و ممکن است دیمن syslog شما شکایت کند.

پیاده‌سازی گزارش‌گیری ساختاریافته (structured logging)

اگرچه بیشتر پیام‌های logging برای خواندن توسط انسان در نظر گرفته شده‌اند و بنابراین به‌راحتی قابل تجزیه توسط ماشین نیستند، ممکن است شرایطی وجود داشته باشد که بخواهید پیام‌ها را در یک قالب ساختاریافته خروجی دهید که قابل تجزیه توسط یک برنامه باشد (بدون نیاز به عبارات باقاعده‌ی پیچیده برای تجزیه‌ی پیام logging). دستیابی به این هدف با استفاده از بسته‌ی logging ساده است. روش‌های متعددی برای رسیدن به این هدف وجود دارد، اما روش زیر یک رویکرد ساده است که از JSON برای سریال‌سازی رویداد به شیوه‌ای قابل تجزیه توسط ماشین استفاده می‌کند:

import json
import logging

class StructuredMessage:
    def __init__(self, message, /, **kwargs):
        self.message = message
        self.kwargs = kwargs

    def __str__(self):
        return '%s >>> %s' % (self.message, json.dumps(self.kwargs))

_ = StructuredMessage   # optional, to improve readability

logging.basicConfig(level=logging.INFO, format='%(message)s')
logging.info(_('message 1', foo='bar', bar='baz', num=123, fnum=123.456))

اگر اسکریپت بالا اجرا شود، خروجی زیر را چاپ می‌کند:

message 1 >>> {"fnum": 123.456, "num": 123, "bar": "baz", "foo": "bar"}

توجه داشته باشید که ترتیب آیتم‌ها ممکن است بسته به نسخه پایتون مورد استفاده متفاوت باشد.

اگر به پردازش تخصصی‌تر نیاز دارید، می‌توانید از یک کدگذار JSON سفارشی استفاده کنید، مانند مثال کامل زیر:

import json
import logging


class Encoder(json.JSONEncoder):
    def default(self, o):
        if isinstance(o, set):
            return tuple(o)
        elif isinstance(o, str):
            return o.encode('unicode_escape').decode('ascii')
        return super().default(o)

class StructuredMessage:
    def __init__(self, message, /, **kwargs):
        self.message = message
        self.kwargs = kwargs

    def __str__(self):
        s = Encoder().encode(self.kwargs)
        return '%s >>> %s' % (self.message, s)

_ = StructuredMessage   # optional, to improve readability

def main():
    logging.basicConfig(level=logging.INFO, format='%(message)s')
    logging.info(_('message 1', set_value={1, 2, 3}, snowman='\u2603'))

if __name__ == '__main__':
    main()

هنگامی که اسکریپت بالا اجرا می‌شود، خروجی زیر را چاپ می‌کند:

message 1 >>> {"snowman": "\u2603", "set_value": [1, 2, 3]}

توجه داشته باشید که ترتیب آیتم‌ها ممکن است بسته به نسخه پایتون مورد استفاده متفاوت باشد.

سفارشی‌سازی هندلرها با dictConfig()

زمان‌هایی وجود دارد که می‌خواهید هندلرهای گزارش‌گیری را به شیوه‌های خاصی سفارشی‌سازی کنید، و اگر از dictConfig() استفاده کنید، ممکن است بتوانید این کار را بدون زیرکلاس‌سازی انجام دهید. به‌عنوان مثال، در نظر بگیرید که ممکن است بخواهید مالکیت یک پرونده گزارش را تنظیم کنید. در POSIX، این کار به‌راحتی با استفاده از shutil.chown() انجام می‌شود، اما هندلرهای پرونده در stdlib پشتیبانی توکار ارائه نمی‌دهند. می‌توانید ایجاد هندلر را با استفاده از یک تابع ساده مانند:

def owned_file_handler(filename, mode='a', encoding=None, owner=None):
    if owner:
        if not os.path.exists(filename):
            open(filename, 'a').close()
        shutil.chown(filename, *owner)
    return logging.FileHandler(filename, mode, encoding)

سپس می‌توانید در یک پیکربندی گزارش (logging configuration) که به dictConfig() داده می‌شود، مشخص کنید که یک هندلری گزارش (logging handler) با فراخوانی این تابع ایجاد شود:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'default': {
            'format': '%(asctime)s %(levelname)s %(name)s %(message)s'
        },
    },
    'handlers': {
        'file':{
            # The values below are popped from this dictionary and
            # used to create the handler, set the handler's level and
            # its formatter.
            '()': owned_file_handler,
            'level':'DEBUG',
            'formatter': 'default',
            # The values below are passed to the handler creator callable
            # as keyword arguments.
            'owner': ['pulse', 'pulse'],
            'filename': 'chowntest.log',
            'mode': 'w',
            'encoding': 'utf-8',
        },
    },
    'root': {
        'handlers': ['file'],
        'level': 'DEBUG',
    },
}

در این مثال، من مالکیت را صرفاً برای اهداف نمایشی، با استفاده از کاربر و گروه pulse تنظیم می‌کنم. با ترکیب این موارد در یک اسکریپت کاربردی، chowntest.py:

import logging, logging.config, os, shutil

def owned_file_handler(filename, mode='a', encoding=None, owner=None):
    if owner:
        if not os.path.exists(filename):
            open(filename, 'a').close()
        shutil.chown(filename, *owner)
    return logging.FileHandler(filename, mode, encoding)

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'default': {
            'format': '%(asctime)s %(levelname)s %(name)s %(message)s'
        },
    },
    'handlers': {
        'file':{
            # The values below are popped from this dictionary and
            # used to create the handler, set the handler's level and
            # its formatter.
            '()': owned_file_handler,
            'level':'DEBUG',
            'formatter': 'default',
            # The values below are passed to the handler creator callable
            # as keyword arguments.
            'owner': ['pulse', 'pulse'],
            'filename': 'chowntest.log',
            'mode': 'w',
            'encoding': 'utf-8',
        },
    },
    'root': {
        'handlers': ['file'],
        'level': 'DEBUG',
    },
}

logging.config.dictConfig(LOGGING)
logger = logging.getLogger('mylogger')
logger.debug('A debug message')

برای اجرای این، احتمالاً باید آن را به‌عنوان root اجرا کنید:

$ sudo python3.3 chowntest.py
$ cat chowntest.log
2013-11-05 09:34:51,128 DEBUG mylogger A debug message
$ ls -l chowntest.log
-rw-r--r-- 1 pulse pulse 55 2013-11-05 09:34 chowntest.log

توجه داشته باشید که این مثال از پایتون 3.3 استفاده می‌کند، زیرا shutil.chown() در همین نسخه معرفی شده است. این روش باید با هر نسخه‌ای از پایتون که از dictConfig() پشتیبانی می‌کند کار کند؛ یعنی پایتون 2.7، 3.2 یا جدیدتر. در نسخه‌های پیش از 3.3، شما باید تغییر واقعی مالکیت را مثلاً با استفاده از os.chown() پیاده‌سازی کنید.

در عمل، ممکن است تابع ایجادکننده‌ی هندلر در یک ماژول کمکی در جایی از پروژه‌ی شما باشد. به‌جای خط موجود در پیکربندی:

'()': owned_file_handler,

می‌توانید برای مثال از آن استفاده کنید:

'()': 'ext://project.util.owned_file_handler',

که در آن می‌توانید project.util را با نام واقعی بسته‌ای که تابع در آن قرار دارد جایگزین کنید. در اسکریپت قابل‌اجرای بالا، استفاده از 'ext://__main__.owned_file_handler' باید کار کند. در اینجا، شیء فراخوانی‌پذیر واقعی توسط dictConfig() از مشخصه‌ی ext:// تعیین می‌شود.

امید است این نمونه همچنین نشان دهد که چگونه می‌توانید انواع دیگر تغییر پرونده را نیز به همین روش پیاده‌سازی کنید؛ برای مثال، تنظیم بیت‌های دسترسی مشخص POSIX (POSIX permission bits) با استفاده از os.chmod().

البته، می‌توان این رویکرد را به انواع دیگری از هندلر، غیر از FileHandler نیز گسترش داد؛ برای مثال، یکی از هندلرهای پرونده چرخشی، یا نوع کاملاً متفاوتی از هندلر.

استفاده از سبک‌های قالب‌بندی خاص در سراسر برنامه شما

در پایتون 3.2، یک پارامتر کلیدواژه‌ای style به Formatter اضافه شد که با وجود داشتن مقدار پیش‌فرض % برای سازگاری با نسخه‌های قبلی، امکان تعیین { یا $ را برای پشتیبانی از شیوه‌های قالب‌بندی پشتیبانی‌شده در str.format() و string.Template فراهم می‌کرد. توجه داشته باشید که این گزینه قالب‌بندی پیام‌های گزارش را برای خروجی نهایی به گزارش‌ها تعیین می‌کند و کاملاً مستقل از چگونگی ساخت یک پیام گزارش منفرد است.

فراخوانی‌های گزارش (debug()، info() و غیره) فقط پارامترهای جایگاهی را برای خودِ پیام گزارش واقعی می‌پذیرند و پارامترهای کلیدواژه‌ای تنها برای تعیین گزینه‌هایی درباره‌ی نحوه‌ی مدیریت فراخوانی گزارش استفاده می‌شوند (برای مثال، پارامتر کلیدواژه‌ای exc_info برای نشان دادن اینکه اطلاعات ردگیری پشته باید ثبت شود، یا پارامتر کلیدواژه‌ای extra برای نشان دادن اطلاعات زمینه‌ای اضافی که باید به گزارش اضافه شود). بنابراین نمی‌توانید مستقیماً فراخوانی‌های گزارش را با سینتکس str.format() یا string.Template انجام دهید، زیرا بسته‌ی logging به‌صورت داخلی از %-formatting برای ادغام رشته‌ی قالب و آرگومان‌های متغیر استفاده می‌کند. در صورت حفظ سازگاری با عقب، این قابل تغییر نخواهد بود، زیرا تمام فراخوانی‌های گزارش در کدهای موجود از رشته‌های %-format استفاده خواهند کرد.

پیشنهادهایی برای مرتبط کردن سبک‌های قالب‌بندی با گزارش‌گیرهای خاص مطرح شده است، اما آن رویکرد نیز با مشکلات سازگاری با نسخه‌های پیشین مواجه می‌شود، زیرا هر کد موجودی ممکن است از یک نام گزارش‌گیر مشخص و از %-formatting استفاده کند.

برای اینکه گزارش کردن میان هر کتابخانه شخص ثالثی و کد شما به‌صورت تعامل‌پذیر کار کند، تصمیم‌های مربوط به قالب‌بندی باید در سطح تک‌تک فراخوانی‌های گزارش اتخاذ شوند. این موضوع چند راه برای پشتیبانی از سبک‌های قالب‌بندی جایگزین باز می‌کند.

استفاده از کارخانه‌های LogRecord

در Python 3.2، همراه با تغییرات Formatter که در بالا ذکر شد، بسته‌ی logging این قابلیت را یافت که به کاربران اجازه دهد زیرکلاس‌های LogRecord خودشان را با استفاده از تابع setLogRecordFactory() تنظیم کنند. شما می‌توانید از این امکان برای تنظیم زیرکلاس خودتان از LogRecord استفاده کنید، به‌طوری که با بازنویسی متد getMessage() رفتار درست را داشته باشد. پیاده‌سازی این متد در کلاس پایه، جایی است که قالب‌بندی msg % args انجام می‌شود و شما می‌توانید قالب‌بندی جایگزین خود را به‌جای آن به‌کار ببرید؛ با این حال، باید دقت کنید که از همه‌ی سبک‌های قالب‌بندی پشتیبانی کنید و قالب‌بندی درصدی (%-formatting) را به‌عنوان پیش‌فرض مجاز بدانید، تا تعامل‌پذیری با سایر کدها تضمین شود. همچنین باید دقت کنید که str(self.msg) را فراخوانی کنید، درست همان‌طور که پیاده‌سازی پایه این کار را انجام می‌دهد.

برای اطلاعات بیشتر، به مستندات مرجع درباره setLogRecordFactory() و LogRecord مراجعه کنید.

استفاده از اشیای پیام سفارشی

راه دیگری وجود دارد، شاید ساده‌تر، که می‌توانید از قالب‌بندی {}- و $- برای ساخت پیام‌های گزارش مستقل خود استفاده کنید. ممکن است به یاد داشته باشید (از استفاده از اشیاء دلخواه به‌عنوان پیام) که هنگام گزارش‌گیری می‌توانید از یک شیء دلخواه به‌عنوان رشته‌ی قالب پیام استفاده کنید و اینکه بسته‌ی logging تابع str() را روی آن شیء فراخوانی می‌کند تا رشته‌ی قالب واقعی به دست آید. دو کلاس زیر را در نظر بگیرید:

class BraceMessage:
    def __init__(self, fmt, /, *args, **kwargs):
        self.fmt = fmt
        self.args = args
        self.kwargs = kwargs

    def __str__(self):
        return self.fmt.format(*self.args, **self.kwargs)

class DollarMessage:
    def __init__(self, fmt, /, **kwargs):
        self.fmt = fmt
        self.kwargs = kwargs

    def __str__(self):
        from string import Template
        return Template(self.fmt).substitute(**self.kwargs)

می‌توان از هر یک از این دو به‌جای یک رشته‌ی قالب استفاده کرد تا امکان به‌کارگیری قالب‌بندی {} یا $ برای ساخت بخش واقعی «پیام» فراهم شود؛ بخشی که در خروجی گزارش قالب‌بندی‌شده به‌جای «%(message)s» یا «{message}» یا «$message» ظاهر می‌شود. اگر هر بار که می‌خواهید چیزی را گزارش کنید، استفاده از نام کلاس‌ها را کمی دشوار می‌دانید، می‌توانید با استفاده از یک نام مستعار مانند M یا _ برای پیام، آن را مطلوب‌تر کنید (یا شاید __، اگر از _ برای محلی‌سازی استفاده می‌کنید).

نمونه‌هایی از این رویکرد در زیر آمده است. ابتدا، قالب‌بندی با str.format():

>>> __ = BraceMessage
>>> print(__('Message with {0} {1}', 2, 'placeholders'))
Message with 2 placeholders
>>> class Point: pass
...
>>> p = Point()
>>> p.x = 0.5
>>> p.y = 0.5
>>> print(__('Message with coordinates: ({point.x:.2f}, {point.y:.2f})', point=p))
Message with coordinates: (0.50, 0.50)

دوم، قالب‌بندی با string.Template:

>>> __ = DollarMessage
>>> print(__('Message with $num $what', num=2, what='placeholders'))
Message with 2 placeholders
>>>

نکته‌ای که باید به آن توجه کنید این است که با این رویکرد هزینه‌ی عملکردی قابل‌توجهی نمی‌پردازید: قالب‌بندی واقعی نه زمانی که فراخوانی گزارش‌گیری را انجام می‌دهید، بلکه زمانی (و در صورتی) انجام می‌شود که پیام گزارش‌شده واقعاً در آستانه‌ی خروجی به یک گزارش توسط یک هندلر باشد. بنابراین تنها نکته‌ی کمی غیرمعمول که ممکن است شما را به اشتباه بیندازد این است که پرانتزها دور رشته‌ی قالب و آرگومان‌ها قرار می‌گیرند، نه فقط دور رشته‌ی قالب. دلیلش این است که نمادگذاری __ صرفاً قند نحوی برای فراخوانی سازنده‌ی یکی از کلاس‌های XXXMessage است که در بالا نشان داده شده‌اند.

پیکربندی فیلترها با dictConfig()

شما می‌توانید فیلترها را با استفاده از dictConfig() پیکربندی کنید، هرچند ممکن است در نگاه اول نحوه انجام این کار واضح نباشد (به همین دلیل این دستور ارائه شده است). از آنجا که Filter تنها کلاس فیلتر موجود در کتابخانه استاندارد است و بعید است نیازمندی‌های زیادی را پوشش دهد (این کلاس فقط به‌عنوان یک کلاس پایه وجود دارد)، معمولاً باید زیرکلاس خود از Filter را با یک متد filter() بازنویسی‌شده تعریف کنید. برای این کار، کلید () را در دیکشنری پیکربندی فیلتر مشخص کنید و یک فراخوانی‌پذیر را تعیین کنید که برای ایجاد فیلتر استفاده خواهد شد (یک کلاس واضح‌ترین گزینه است، اما می‌توانید هر فراخوانی‌پذیری را ارائه دهید که یک نمونه از Filter را برمی‌گرداند). در ادامه یک مثال کامل آمده است:

import logging
import logging.config
import sys

class MyFilter(logging.Filter):
    def __init__(self, param=None):
        self.param = param

    def filter(self, record):
        if self.param is None:
            allow = True
        else:
            allow = self.param not in record.msg
        if allow:
            record.msg = 'changed: ' + record.msg
        return allow

LOGGING = {
    'version': 1,
    'filters': {
        'myfilter': {
            '()': MyFilter,
            'param': 'noshow',
        }
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'filters': ['myfilter']
        }
    },
    'root': {
        'level': 'DEBUG',
        'handlers': ['console']
    },
}

if __name__ == '__main__':
    logging.config.dictConfig(LOGGING)
    logging.debug('hello')
    logging.debug('hello - noshow')

این مثال نشان می‌دهد که چگونه می‌توانید داده‌های پیکربندی را در قالب پارامترهای کلیدواژه‌ای به شیء فراخوانی‌پذیری که نمونه را می‌سازد، منتقل کنید. هنگام اجرا، اسکریپت بالا چاپ خواهد کرد:

changed: hello

که نشان می‌دهد فیلتر همان‌طور که پیکربندی شده است کار می‌کند.

چند نکته‌ی اضافی برای توجه:

• اگر نمی‌توانید در پیکربندی مستقیماً به فراخوانی‌پذیر ارجاع دهید (برای نمونه، اگر در ماژول دیگری قرار دارد و نمی‌توانید آن را مستقیماً در جایی که دیکشنری پیکربندی قرار دارد ایمپورت کنید)، می‌توانید از قالب ext://... همان‌طور که در دسترسی به اشیاء خارجی توضیح داده شده است استفاده کنید. برای نمونه، می‌توانستید در مثال بالا به‌جای MyFilter از متن 'ext://__main__.MyFilter' استفاده کنید.

• علاوه بر فیلترها، این روش می‌تواند برای پیکربندی هندلرهای سفارشی و قالب‌بندهای سفارشی نیز به‌کار رود. برای اطلاعات بیشتر درباره‌ی نحوه‌ی پشتیبانی گزارش‌گیری از استفاده از اشیای تعریف‌شده توسط کاربر در پیکربندی خود، اشیاء تعریف‌شده توسط کاربر را ببینید و دستور پخت دیگر سفارشی‌سازی هندلرها با dictConfig() را در بالا ببینید.

قالب‌بندی سفارشی استثنا

ممکن است گاهی بخواهید قالب‌بندی سفارشی استثنا را انجام دهید — برای مثال، فرض کنید دقیقاً یک خط به‌ازای هر رویداد ثبت‌شده می‌خواهید، حتی زمانی که اطلاعات استثنا وجود دارد. می‌توانید این کار را با یک کلاس قالب‌بند سفارشی انجام دهید، همان‌طور که در مثال زیر نشان داده شده است:

import logging

class OneLineExceptionFormatter(logging.Formatter):
    def formatException(self, exc_info):
        """
        Format an exception so that it prints on a single line.
        """
        result = super().formatException(exc_info)
        return repr(result)  # or format into one line however you want to

    def format(self, record):
        s = super().format(record)
        if record.exc_text:
            s = s.replace('\n', '') + '|'
        return s

def configure_logging():
    fh = logging.FileHandler('output.txt', 'w')
    f = OneLineExceptionFormatter('%(asctime)s|%(levelname)s|%(message)s|',
                                  '%d/%m/%Y %H:%M:%S')
    fh.setFormatter(f)
    root = logging.getLogger()
    root.setLevel(logging.DEBUG)
    root.addHandler(fh)

def main():
    configure_logging()
    logging.info('Sample message')
    try:
        x = 1 / 0
    except ZeroDivisionError as e:
        logging.exception('ZeroDivisionError: %s', e)

if __name__ == '__main__':
    main()

هنگام اجرا، این یک پرونده با دقیقاً دو خط ایجاد می‌کند:

28/01/2015 07:21:23|INFO|Sample message|
28/01/2015 07:21:23|ERROR|ZeroDivisionError: division by zero|'Traceback (most recent call last):\n  File "logtest7.py", line 30, in main\n    x = 1 / 0\nZeroDivisionError: division by zero'|

اگرچه روش فوق ساده است، اما نشان می‌دهد که چگونه می‌توان اطلاعات استثنا را مطابق میل شما قالب‌بندی کرد. ماژول traceback ممکن است برای نیازهای تخصصی‌تر مفید باشد.

بیان پیام‌های گزارش‌گیری

ممکن است موقعیت‌هایی وجود داشته باشد که مطلوب است پیام‌های گزارش به‌جای قالب دیداری، در قالب شنیداری ارائه شوند. اگر قابلیت تبدیل متن به گفتار (TTS) در سیستم شما در دسترس باشد، انجام این کار آسان است، حتی اگر اتصال پایتون (Python binding) نداشته باشد. بیشتر سیستم‌های TTS یک برنامه‌ی خط فرمان دارند که می‌توانید آن را اجرا کنید، و می‌توان آن را از یک هندلر با استفاده از subprocess فراخوانی کرد. در اینجا فرض بر این است که برنامه‌های خط فرمان TTS انتظار تعامل با کاربران را ندارند یا برای تکمیل شدن به زمان زیادی نیاز ندارند، و اینکه نرخ پیام‌های گزارش‌شده آن‌قدر بالا نیست که کاربر را با پیام‌ها غرق کند، و اینکه قابل قبول است پیام‌ها یکی‌یکی به‌جای همزمان گفته شوند. پیاده‌سازی مثال زیر، پیش از پردازش پیام بعدی، منتظر می‌ماند تا یک پیام گفته شود، و این ممکن است باعث شود سایر هندلرها در انتظار بمانند. در اینجا یک مثال کوتاه برای نشان دادن این رویکرد آمده است که فرض می‌کند بسته‌ی TTS espeak در دسترس است:

import logging
import subprocess
import sys

class TTSHandler(logging.Handler):
    def emit(self, record):
        msg = self.format(record)
        # Speak slowly in a female English voice
        cmd = ['espeak', '-s150', '-ven+f3', msg]
        p = subprocess.Popen(cmd, stdout=subprocess.PIPE,
                             stderr=subprocess.STDOUT)
        # wait for the program to finish
        p.communicate()

def configure_logging():
    h = TTSHandler()
    root = logging.getLogger()
    root.addHandler(h)
    # the default formatter just returns the message
    root.setLevel(logging.DEBUG)

def main():
    logging.info('Hello')
    logging.debug('Goodbye')

if __name__ == '__main__':
    configure_logging()
    sys.exit(main())

هنگام اجرا، این اسکریپت باید «سلام» و سپس «خداحافظ» را با صدای زن بگوید.

البته می‌توان رویکرد بالا را با سامانه‌های متن به گفتار (TTS) دیگر و حتی سامانه‌های دیگری به‌کلی تطبیق داد، سامانه‌هایی که می‌توانند پیام‌ها را از طریق برنامه‌های خارجی که از خط فرمان اجرا می‌شوند پردازش کنند.

بافر کردن پیام‌های گزارش‌دهی و خروجی دادن آن‌ها به‌صورت شرطی

ممکن است شرایطی وجود داشته باشد که بخواهید پیام‌ها را در یک ناحیه موقت ثبت کنید و تنها در صورت بروز یک شرط خاص آن‌ها را خروجی دهید. برای مثال، ممکن است بخواهید ثبت رویدادهای اشکال‌زدایی را در یک تابع آغاز کنید و اگر تابع بدون خطا به پایان برسد، نخواهید گزارش را با اطلاعات اشکال‌زدایی جمع‌آوری‌شده شلوغ کنید، اما اگر خطایی رخ دهد، بخواهید تمام اطلاعات اشکال‌زدایی نیز همراه با خطا خروجی داده شود.

در اینجا مثالی وجود دارد که نشان می‌دهد چگونه می‌توانید این کار را با استفاده از یک دکوراتور برای توابعی انجام دهید که می‌خواهید گزارش‌گیری در آن‌ها به این شکل رفتار کند. این مثال از logging.handlers.MemoryHandler استفاده می‌کند، که امکان بافر کردن رویدادهای گزارش‌شده را تا زمانی که شرطی رخ دهد فراهم می‌کند؛ در آن نقطه، رویدادهای بافر شده flushed می‌شوند؛ یعنی برای پردازش به یک هندلر دیگر (هندلر target) فرستاده می‌شوند. به‌طور پیش‌فرض، MemoryHandler زمانی تخلیه می‌شود که بافر آن پر شود یا رویدادی که سطح آن بزرگ‌تر یا مساوی با یک آستانه مشخص است مشاهده شود. اگر رفتار تخلیه سفارشی می‌خواهید، می‌توانید از این راهکار با یک زیرکلاس تخصصی‌تر از MemoryHandler استفاده کنید.

اسکریپت نمونه یک تابع ساده، foo، دارد که فقط تمام سطوح گزارش را طی می‌کند، در sys.stderr می‌نویسد که قرار است در چه سطحی گزارش کند، و سپس در عمل پیامی را در آن سطح گزارش می‌کند. شما می‌توانید پارامتری به foo بدهید که اگر مقدار آن true باشد، در سطوح ERROR و CRITICAL گزارش می‌کند؛ در غیر این صورت، فقط در سطوح DEBUG، INFO و WARNING گزارش می‌کند.

این اسکریپت فقط مقدمات آراستن foo با یک دکوراتور را فراهم می‌کند؛ دکوراتوری که گزارش کردن شرطی مورد نیاز را انجام می‌دهد. این دکوراتور یک گزارش‌گیر را به‌عنوان پارامتر می‌گیرد و یک هندلر حافظه را در طول فراخوانی تابع آراسته‌شده متصل می‌کند. علاوه بر این، می‌توان این دکوراتور را با استفاده از یک هندلر هدف، سطحی که تخلیه باید در آن انجام شود، و ظرفیت بافر (تعداد رکوردهای موجود در بافر) نیز پارامتریزه کرد. مقادیر پیش‌فرض این موارد به‌ترتیب عبارت‌اند از یک StreamHandler که به sys.stderr می‌نویسد، logging.ERROR و 100.

این هم اسکریپت:

import logging
from logging.handlers import MemoryHandler
import sys

logger = logging.getLogger(__name__)
logger.addHandler(logging.NullHandler())

def log_if_errors(logger, target_handler=None, flush_level=None, capacity=None):
    if target_handler is None:
        target_handler = logging.StreamHandler()
    if flush_level is None:
        flush_level = logging.ERROR
    if capacity is None:
        capacity = 100
    handler = MemoryHandler(capacity, flushLevel=flush_level, target=target_handler)

    def decorator(fn):
        def wrapper(*args, **kwargs):
            logger.addHandler(handler)
            try:
                return fn(*args, **kwargs)
            except Exception:
                logger.exception('call failed')
                raise
            finally:
                super(MemoryHandler, handler).flush()
                logger.removeHandler(handler)
        return wrapper

    return decorator

def write_line(s):
    sys.stderr.write('%s\n' % s)

def foo(fail=False):
    write_line('about to log at DEBUG ...')
    logger.debug('Actually logged at DEBUG')
    write_line('about to log at INFO ...')
    logger.info('Actually logged at INFO')
    write_line('about to log at WARNING ...')
    logger.warning('Actually logged at WARNING')
    if fail:
        write_line('about to log at ERROR ...')
        logger.error('Actually logged at ERROR')
        write_line('about to log at CRITICAL ...')
        logger.critical('Actually logged at CRITICAL')
    return fail

decorated_foo = log_if_errors(logger)(foo)

if __name__ == '__main__':
    logger.setLevel(logging.DEBUG)
    write_line('Calling undecorated foo with False')
    assert not foo(False)
    write_line('Calling undecorated foo with True')
    assert foo(True)
    write_line('Calling decorated foo with False')
    assert not decorated_foo(False)
    write_line('Calling decorated foo with True')
    assert decorated_foo(True)

هنگامی که این اسکریپت اجرا می‌شود، باید خروجی زیر مشاهده شود:

Calling undecorated foo with False
about to log at DEBUG ...
about to log at INFO ...
about to log at WARNING ...
Calling undecorated foo with True
about to log at DEBUG ...
about to log at INFO ...
about to log at WARNING ...
about to log at ERROR ...
about to log at CRITICAL ...
Calling decorated foo with False
about to log at DEBUG ...
about to log at INFO ...
about to log at WARNING ...
Calling decorated foo with True
about to log at DEBUG ...
about to log at INFO ...
about to log at WARNING ...
about to log at ERROR ...
Actually logged at DEBUG
Actually logged at INFO
Actually logged at WARNING
Actually logged at ERROR
about to log at CRITICAL ...
Actually logged at CRITICAL

همان‌طور که می‌بینید، خروجی واقعی گزارش کردن تنها زمانی رخ می‌دهد که رویدادی گزارش شود که شدت آن ERROR یا بالاتر باشد، اما در آن حالت، هر یک از رویدادهای قبلی با شدت‌های پایین‌تر نیز گزارش می‌شوند.

البته می‌توانید از روش‌های مرسوم دکوراسیون استفاده کنید:

@log_if_errors(logger)
def foo(fail=False):
    ...

ارسال پیام‌های گزارش به ایمیل، همراه با بافرینگ (buffering)

برای نشان دادن این‌که چگونه می‌توانید پیام‌های گزارش را از طریق ایمیل ارسال کنید، به‌گونه‌ای که تعداد مشخصی پیام در هر ایمیل فرستاده شود، می‌توانید زیرکلاسی از BufferingHandler بسازید. در مثال زیر، که می‌توانید آن را متناسب با نیازهای خاص خود تطبیق دهید، یک مهار آزمون (test harness) ساده فراهم شده است که به شما امکان می‌دهد اسکریپت را با آرگومان‌های خط فرمان اجرا کنید؛ این آرگومان‌ها آنچه را که معمولاً برای ارسال موارد از طریق SMTP به آن نیاز دارید مشخص می‌کنند. (برای دیدن آرگومان‌های ضروری و اختیاری، اسکریپت بارگیری‌شده را با آرگومان -h اجرا کنید.)

import logging
import logging.handlers
import smtplib

class BufferingSMTPHandler(logging.handlers.BufferingHandler):
    def __init__(self, mailhost, port, username, password, fromaddr, toaddrs,
                 subject, capacity):
        logging.handlers.BufferingHandler.__init__(self, capacity)
        self.mailhost = mailhost
        self.mailport = port
        self.username = username
        self.password = password
        self.fromaddr = fromaddr
        if isinstance(toaddrs, str):
            toaddrs = [toaddrs]
        self.toaddrs = toaddrs
        self.subject = subject
        self.setFormatter(logging.Formatter("%(asctime)s %(levelname)-5s %(message)s"))

    def flush(self):
        if len(self.buffer) > 0:
            try:
                smtp = smtplib.SMTP(self.mailhost, self.mailport)
                smtp.starttls()
                smtp.login(self.username, self.password)
                msg = "From: %s\r\nTo: %s\r\nSubject: %s\r\n\r\n" % (self.fromaddr, ','.join(self.toaddrs), self.subject)
                for record in self.buffer:
                    s = self.format(record)
                    msg = msg + s + "\r\n"
                smtp.sendmail(self.fromaddr, self.toaddrs, msg)
                smtp.quit()
            except Exception:
                if logging.raiseExceptions:
                    raise
            self.buffer = []

if __name__ == '__main__':
    import argparse

    ap = argparse.ArgumentParser()
    aa = ap.add_argument
    aa('host', metavar='HOST', help='SMTP server')
    aa('--port', '-p', type=int, default=587, help='SMTP port')
    aa('user', metavar='USER', help='SMTP username')
    aa('password', metavar='PASSWORD', help='SMTP password')
    aa('to', metavar='TO', help='Addressee for emails')
    aa('sender', metavar='SENDER', help='Sender email address')
    aa('--subject', '-s',
       default='Test Logging email from Python logging module (buffering)',
       help='Subject of email')
    options = ap.parse_args()
    logger = logging.getLogger()
    logger.setLevel(logging.DEBUG)
    h = BufferingSMTPHandler(options.host, options.port, options.user,
                             options.password, options.sender,
                             options.to, options.subject, 10)
    logger.addHandler(h)
    for i in range(102):
        logger.info("Info index = %d", i)
    h.flush()
    h.close()

اگر این اسکریپت را اجرا کنید و سرور SMTP شما به‌درستی پیکربندی شده باشد، متوجه خواهید شد که این اسکریپت یازده ایمیل به گیرنده‌ای که مشخص می‌کنید ارسال می‌کند. هر یک از ده ایمیل اول ده پیام گزارش خواهند داشت و ایمیل یازدهم دو پیام خواهد داشت. این‌ها در مجموع ۱۰۲ پیام را تشکیل می‌دهند، همان‌طور که در اسکریپت مشخص شده است.

قالب‌بندی زمان‌ها با استفاده از UTC (GMT) از طریق پیکربندی

گاهی ممکن است بخواهید زمان‌ها را با استفاده از UTC قالب‌بندی کنید، که این کار را می‌توان با استفاده از کلاسی مانند UTCFormatter انجام داد، همان‌طور که در ادامه نشان داده شده است:

import logging
import time

class UTCFormatter(logging.Formatter):
    converter = time.gmtime

و سپس می‌توانید از UTCFormatter در کد خود به جای Formatter استفاده کنید. اگر می‌خواهید این کار را از طریق پیکربندی انجام دهید، می‌توانید از API dictConfig() با رویکردی که در مثال کامل زیر نشان داده شده است استفاده کنید:

import logging
import logging.config
import time

class UTCFormatter(logging.Formatter):
    converter = time.gmtime

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'utc': {
            '()': UTCFormatter,
            'format': '%(asctime)s %(message)s',
        },
        'local': {
            'format': '%(asctime)s %(message)s',
        }
    },
    'handlers': {
        'console1': {
            'class': 'logging.StreamHandler',
            'formatter': 'utc',
        },
        'console2': {
            'class': 'logging.StreamHandler',
            'formatter': 'local',
        },
    },
    'root': {
        'handlers': ['console1', 'console2'],
   }
}

if __name__ == '__main__':
    logging.config.dictConfig(LOGGING)
    logging.warning('The local time is %s', time.asctime())

هنگامی که این اسکریپت اجرا می‌شود، باید چیزی شبیه به این چاپ کند:

2015-10-17 12:53:29,501 The local time is Sat Oct 17 13:53:29 2015
2015-10-17 13:53:29,501 The local time is Sat Oct 17 13:53:29 2015

که نشان می‌دهد زمان چگونه هم به‌صورت زمان محلی و هم به‌صورت UTC قالب‌بندی می‌شود، یکی برای هر هندلر .

استفاده از مدیر زمینه برای گزارش‌گیری انتخابی

مواردی وجود دارد که تغییر موقت پیکربندی گزارش (logging configuration) و بازگرداندن آن به حالت پیشین پس از انجام کاری مفید است. برای این منظور، مدیر زمینه آشکارترین راه برای ذخیره و بازیابی زمینه‌ی گزارش است. در اینجا یک مثال ساده از چنین مدیر زمینه‌ای آمده است که به شما امکان می‌دهد به‌صورت اختیاری سطح گزارش (logging level) را تغییر دهید و یک هندلر گزارش (logging handler) را صرفاً در محدوده‌ی مدیر زمینه اضافه کنید:

import logging
import sys

class LoggingContext:
    def __init__(self, logger, level=None, handler=None, close=True):
        self.logger = logger
        self.level = level
        self.handler = handler
        self.close = close

    def __enter__(self):
        if self.level is not None:
            self.old_level = self.logger.level
            self.logger.setLevel(self.level)
        if self.handler:
            self.logger.addHandler(self.handler)

    def __exit__(self, et, ev, tb):
        if self.level is not None:
            self.logger.setLevel(self.old_level)
        if self.handler:
            self.logger.removeHandler(self.handler)
        if self.handler and self.close:
            self.handler.close()
        # implicit return of None => don't swallow exceptions

اگر یک مقدار سطح مشخص کنید، سطح گزارش‌گیر در محدوده‌ی بلوک with که توسط مدیر زمینه پوشش داده شده است، روی آن مقدار تنظیم می‌شود. اگر یک هندلر مشخص کنید، هنگام ورود به بلوک به گزارش‌گیر اضافه می‌شود و هنگام خروج از بلوک حذف می‌شود. همچنین می‌توانید از مدیر بخواهید که در زمان خروج از بلوک، هندلر را برای شما ببندد — اگر دیگر به آن هندلر نیازی ندارید، می‌توانید این کار را انجام دهید.

برای نشان دادن نحوه‌ی عملکرد آن، می‌توانیم قطعه‌کد زیر را به مورد بالا اضافه کنیم:

if __name__ == '__main__':
    logger = logging.getLogger('foo')
    logger.addHandler(logging.StreamHandler())
    logger.setLevel(logging.INFO)
    logger.info('1. This should appear just once on stderr.')
    logger.debug('2. This should not appear.')
    with LoggingContext(logger, level=logging.DEBUG):
        logger.debug('3. This should appear once on stderr.')
    logger.debug('4. This should not appear.')
    h = logging.StreamHandler(sys.stdout)
    with LoggingContext(logger, level=logging.DEBUG, handler=h, close=True):
        logger.debug('5. This should appear twice - once on stderr and once on stdout.')
    logger.info('6. This should appear just once on stderr.')
    logger.debug('7. This should not appear.')

ابتدا سطح گزارش‌گیر را روی INFO تنظیم می‌کنیم، بنابراین پیام ۱ نمایش داده می‌شود و پیام ۲ نمایش داده نمی‌شود. سپس سطح را به‌طور موقت در بلوک with زیر به DEBUG تغییر می‌دهیم، بنابراین پیام ۳ نمایش داده می‌شود. پس از خروج از بلوک، سطح گزارش‌گیر به INFO بازگردانده می‌شود و بنابراین پیام ۴ نمایش داده نمی‌شود. در بلوک with بعدی، دوباره سطح را روی DEBUG تنظیم می‌کنیم، اما همچنین یک هندلر برای نوشتن در sys.stdout اضافه می‌کنیم. بنابراین، پیام ۵ دو بار در کنسول نمایش داده می‌شود (یک بار از طریق stderr و یک بار از طریق stdout). پس از تکمیل دستور with، وضعیت مانند قبل است، بنابراین پیام ۶ نمایش داده می‌شود (مانند پیام ۱) در حالی که پیام ۷ نمایش داده نمی‌شود (دقیقاً مانند پیام ۲).

اگر اسکریپت حاصل را اجرا کنیم، نتیجه به‌صورت زیر است:

$ python logctx.py
1. This should appear just once on stderr.
3. This should appear once on stderr.
5. This should appear twice - once on stderr and once on stdout.
5. This should appear twice - once on stderr and once on stdout.
6. This should appear just once on stderr.

اگر دوباره آن را اجرا کنیم، اما stderr را به /dev/null هدایت کنیم، مورد زیر را می‌بینیم که تنها پیام نوشته‌شده در stdout است:

$ python logctx.py 2>/dev/null
5. This should appear twice - once on stderr and once on stdout.

بار دیگر، اما با pipe کردن (piping) stdout به /dev/null، این خروجی را دریافت می‌کنیم:

$ python logctx.py >/dev/null
1. This should appear just once on stderr.
3. This should appear once on stderr.
5. This should appear twice - once on stderr and once on stdout.
6. This should appear just once on stderr.

در این حالت، پیام شماره‌ی ۵ چاپ‌شده در stdout، همان‌طور که انتظار می‌رود ظاهر نمی‌شود.

البته، رویکرد توصیف‌شده در اینجا می‌تواند تعمیم داده شود، برای مثال برای اتصال موقت فیلترهای گزارش (logging filters). توجه داشته باشید که کد فوق در Python 2 و همچنین در Python 3 کار می‌کند.

قالب شروع برنامه خط فرمان

در اینجا مثالی آمده است که نشان می‌دهد چگونه می‌توانید:

• استفاده از سطح گزارش‌گذاری بر اساس آرگومان‌های خط فرمان

• اعزام به چند زیرفرمان در پرونده‌های جداگانه، به‌گونه‌ای که همه‌ی آن‌ها گزارش‌گیری را در یک سطح و به‌شکلی یکسان انجام دهند

• از پیکربندی ساده و حداقلی استفاده کنید

فرض کنید یک برنامه‌ی خط فرمانی داریم که وظیفه‌ی آن توقف، راه‌اندازی یا راه‌اندازی مجدد برخی سرویس‌ها است. این برنامه می‌تواند برای مقاصد نمایشی به‌صورت پرونده app.py سازمان‌دهی شود که اسکریپت اصلی برنامه است و دستورات جداگانه در start.py، stop.py و restart.py پیاده‌سازی شده‌اند. همچنین فرض کنید می‌خواهیم سطح جزئیات برنامه را از طریق یک آرگومان خط فرمان کنترل کنیم، با مقدار پیش‌فرض logging.INFO. در ادامه یک روش برای نوشتن app.py آمده است:

import argparse
import importlib
import logging
import os
import sys

def main(args=None):
    scriptname = os.path.basename(__file__)
    parser = argparse.ArgumentParser(scriptname)
    levels = ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
    parser.add_argument('--log-level', default='INFO', choices=levels)
    subparsers = parser.add_subparsers(dest='command',
                                       help='Available commands:')
    start_cmd = subparsers.add_parser('start', help='Start a service')
    start_cmd.add_argument('name', metavar='NAME',
                           help='Name of service to start')
    stop_cmd = subparsers.add_parser('stop',
                                     help='Stop one or more services')
    stop_cmd.add_argument('names', metavar='NAME', nargs='+',
                          help='Name of service to stop')
    restart_cmd = subparsers.add_parser('restart',
                                        help='Restart one or more services')
    restart_cmd.add_argument('names', metavar='NAME', nargs='+',
                             help='Name of service to restart')
    options = parser.parse_args()
    # the code to dispatch commands could all be in this file. For the purposes
    # of illustration only, we implement each command in a separate module.
    try:
        mod = importlib.import_module(options.command)
        cmd = getattr(mod, 'command')
    except (ImportError, AttributeError):
        print('Unable to find the code for command \'%s\'' % options.command)
        return 1
    # Could get fancy here and load configuration from file or dictionary
    logging.basicConfig(level=options.log_level,
                        format='%(levelname)s %(name)s %(message)s')
    cmd(options)

if __name__ == '__main__':
    sys.exit(main())

و می‌توان فرمان‌های start، stop و restart را در ماژول‌های جداگانه پیاده‌سازی کرد، مثلاً برای شروع به این صورت:

# start.py
import logging

logger = logging.getLogger(__name__)

def command(options):
    logger.debug('About to start %s', options.name)
    # actually do the command processing here ...
    logger.info('Started the \'%s\' service.', options.name)

و بنابراین برای توقف:

# stop.py
import logging

logger = logging.getLogger(__name__)

def command(options):
    n = len(options.names)
    if n == 1:
        plural = ''
        services = '\'%s\'' % options.names[0]
    else:
        plural = 's'
        services = ', '.join('\'%s\'' % name for name in options.names)
        i = services.rfind(', ')
        services = services[:i] + ' and ' + services[i + 2:]
    logger.debug('About to stop %s', services)
    # actually do the command processing here ...
    logger.info('Stopped the %s service%s.', services, plural)

و به‌طور مشابه برای راه‌اندازی مجدد:

# restart.py
import logging

logger = logging.getLogger(__name__)

def command(options):
    n = len(options.names)
    if n == 1:
        plural = ''
        services = '\'%s\'' % options.names[0]
    else:
        plural = 's'
        services = ', '.join('\'%s\'' % name for name in options.names)
        i = services.rfind(', ')
        services = services[:i] + ' and ' + services[i + 2:]
    logger.debug('About to restart %s', services)
    # actually do the command processing here ...
    logger.info('Restarted the %s service%s.', services, plural)

اگر این برنامه را با سطح گزارش پیش‌فرض اجرا کنیم، خروجی‌ای مانند این دریافت می‌کنیم:

$ python app.py start foo
INFO start Started the 'foo' service.

$ python app.py stop foo bar
INFO stop Stopped the 'foo' and 'bar' services.

$ python app.py restart foo bar baz
INFO restart Restarted the 'foo', 'bar' and 'baz' services.

واژه اول سطح گزارش‌دهی است، و واژه دوم نام ماژول یا بسته‌ی محلی است که رویداد در آن ثبت شده است.

اگر سطح گزارش‌دهی را تغییر دهیم، می‌توانیم اطلاعاتی را که به گزارش فرستاده می‌شود، تغییر دهیم. برای مثال، اگر اطلاعات بیشتری بخواهیم:

$ python app.py --log-level DEBUG start foo
DEBUG start About to start foo
INFO start Started the 'foo' service.

$ python app.py --log-level DEBUG stop foo bar
DEBUG stop About to stop 'foo' and 'bar'
INFO stop Stopped the 'foo' and 'bar' services.

$ python app.py --log-level DEBUG restart foo bar baz
DEBUG restart About to restart 'foo', 'bar' and 'baz'
INFO restart Restarted the 'foo', 'bar' and 'baz' services.

و اگر کمتر بخواهیم:

$ python app.py --log-level WARNING start foo
$ python app.py --log-level WARNING stop foo bar
$ python app.py --log-level WARNING restart foo bar baz

در این حالت، دستورها چیزی را در کنسول چاپ نمی‌کنند، زیرا هیچ چیزی در سطح WARNING یا بالاتر توسط آن‌ها ثبت نمی‌شود.

یک رابط کاربری گرافیکی Qt برای گزارش‌گیری

پرسشی که هر از چند گاهی مطرح می‌شود، درباره‌ی نحوه‌ی ثبت گزارش در یک برنامه‌ی GUI است. چارچوب Qt یک چارچوب رابط کاربری محبوب و بین‌سکویی است که اتصال‌های پایتون را با استفاده از کتابخانه‌های PySide2 یا PyQt5 فراهم می‌کند.

مثال زیر نشان می‌دهد که چگونه می‌توان گزارش‌ها را در یک GUI Qt ثبت کرد. این مثال یک کلاس ساده QtHandler را معرفی می‌کند که یک شیء فراخوانی‌پذیر می‌گیرد. این شیء باید یک جایگاه در نخ اصلی باشد و به‌روزرسانی‌های GUI را انجام دهد. همچنین یک نخ کاری ایجاد می‌شود تا نشان داده شود که چگونه می‌توانید گزارش‌ها را هم از خود UI (از طریق یک دکمه برای ثبت گزارش دستی) و هم از یک نخ کاری که کاری را در پس‌زمینه انجام می‌دهد، در GUI ثبت کنید (در اینجا، فقط پیام‌ها را در سطوح تصادفی و با تأخیرهای کوتاه تصادفی بین آن‌ها ثبت می‌کند).

نخ کارگر به جای ماژول threading، با استفاده از کلاس QThread در Qt پیاده‌سازی شده است، زیرا شرایطی وجود دارد که باید از QThread استفاده کرد، که یکپارچگی بهتری با سایر کامپوننت‌های Qt دارد.

این کد باید با نسخه‌های اخیر هر یک از PySide6، PyQt6، PySide2 یا PyQt5 کار کند. شما باید بتوانید این رویکرد را با نسخه‌های پیشین Qt تطبیق دهید. لطفاً برای اطلاعات دقیق‌تر به کامنت‌های موجود در قطعه‌کد مراجعه کنید.

import logging
import random
import sys
import time

# Deal with minor differences between different Qt packages
try:
    from PySide6 import QtCore, QtGui, QtWidgets
    Signal = QtCore.Signal
    Slot = QtCore.Slot
except ImportError:
    try:
        from PyQt6 import QtCore, QtGui, QtWidgets
        Signal = QtCore.pyqtSignal
        Slot = QtCore.pyqtSlot
    except ImportError:
        try:
            from PySide2 import QtCore, QtGui, QtWidgets
            Signal = QtCore.Signal
            Slot = QtCore.Slot
        except ImportError:
            from PyQt5 import QtCore, QtGui, QtWidgets
            Signal = QtCore.pyqtSignal
            Slot = QtCore.pyqtSlot

logger = logging.getLogger(__name__)


#
# Signals need to be contained in a QObject or subclass in order to be correctly
# initialized.
#
class Signaller(QtCore.QObject):
    signal = Signal(str, logging.LogRecord)

#
# Output to a Qt GUI is only supposed to happen on the main thread. So, this
# handler is designed to take a slot function which is set up to run in the main
# thread. In this example, the function takes a string argument which is a
# formatted log message, and the log record which generated it. The formatted
# string is just a convenience - you could format a string for output any way
# you like in the slot function itself.
#
# You specify the slot function to do whatever GUI updates you want. The handler
# doesn't know or care about specific UI elements.
#
class QtHandler(logging.Handler):
    def __init__(self, slotfunc, *args, **kwargs):
        super().__init__(*args, **kwargs)
        self.signaller = Signaller()
        self.signaller.signal.connect(slotfunc)

    def emit(self, record):
        s = self.format(record)
        self.signaller.signal.emit(s, record)

#
# This example uses QThreads, which means that the threads at the Python level
# are named something like "Dummy-1". The function below gets the Qt name of the
# current thread.
#
def ctname():
    return QtCore.QThread.currentThread().objectName()


#
# Used to generate random levels for logging.
#
LEVELS = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,
          logging.CRITICAL)

#
# This worker class represents work that is done in a thread separate to the
# main thread. The way the thread is kicked off to do work is via a button press
# that connects to a slot in the worker.
#
# Because the default threadName value in the LogRecord isn't much use, we add
# a qThreadName which contains the QThread name as computed above, and pass that
# value in an "extra" dictionary which is used to update the LogRecord with the
# QThread name.
#
# This example worker just outputs messages sequentially, interspersed with
# random delays of the order of a few seconds.
#
class Worker(QtCore.QObject):
    @Slot()
    def start(self):
        extra = {'qThreadName': ctname() }
        logger.debug('Started work', extra=extra)
        i = 1
        # Let the thread run until interrupted. This allows reasonably clean
        # thread termination.
        while not QtCore.QThread.currentThread().isInterruptionRequested():
            delay = 0.5 + random.random() * 2
            time.sleep(delay)
            try:
                if random.random() < 0.1:
                    raise ValueError('Exception raised: %d' % i)
                else:
                    level = random.choice(LEVELS)
                    logger.log(level, 'Message after delay of %3.1f: %d', delay, i, extra=extra)
            except ValueError as e:
                logger.exception('Failed: %s', e, extra=extra)
            i += 1

#
# Implement a simple UI for this cookbook example. This contains:
#
# * A read-only text edit window which holds formatted log messages
# * A button to start work and log stuff in a separate thread
# * A button to log something from the main thread
# * A button to clear the log window
#
class Window(QtWidgets.QWidget):

    COLORS = {
        logging.DEBUG: 'black',
        logging.INFO: 'blue',
        logging.WARNING: 'orange',
        logging.ERROR: 'red',
        logging.CRITICAL: 'purple',
    }

    def __init__(self, app):
        super().__init__()
        self.app = app
        self.textedit = te = QtWidgets.QPlainTextEdit(self)
        # Set whatever the default monospace font is for the platform
        f = QtGui.QFont('nosuchfont')
        if hasattr(f, 'Monospace'):
            f.setStyleHint(f.Monospace)
        else:
            f.setStyleHint(f.StyleHint.Monospace)  # for Qt6
        te.setFont(f)
        te.setReadOnly(True)
        PB = QtWidgets.QPushButton
        self.work_button = PB('Start background work', self)
        self.log_button = PB('Log a message at a random level', self)
        self.clear_button = PB('Clear log window', self)
        self.handler = h = QtHandler(self.update_status)
        # Remember to use qThreadName rather than threadName in the format string.
        fs = '%(asctime)s %(qThreadName)-12s %(levelname)-8s %(message)s'
        formatter = logging.Formatter(fs)
        h.setFormatter(formatter)
        logger.addHandler(h)
        # Set up to terminate the QThread when we exit
        app.aboutToQuit.connect(self.force_quit)

        # Lay out all the widgets
        layout = QtWidgets.QVBoxLayout(self)
        layout.addWidget(te)
        layout.addWidget(self.work_button)
        layout.addWidget(self.log_button)
        layout.addWidget(self.clear_button)
        self.setFixedSize(900, 400)

        # Connect the non-worker slots and signals
        self.log_button.clicked.connect(self.manual_update)
        self.clear_button.clicked.connect(self.clear_display)

        # Start a new worker thread and connect the slots for the worker
        self.start_thread()
        self.work_button.clicked.connect(self.worker.start)
        # Once started, the button should be disabled
        self.work_button.clicked.connect(lambda : self.work_button.setEnabled(False))

    def start_thread(self):
        self.worker = Worker()
        self.worker_thread = QtCore.QThread()
        self.worker.setObjectName('Worker')
        self.worker_thread.setObjectName('WorkerThread')  # for qThreadName
        self.worker.moveToThread(self.worker_thread)
        # This will start an event loop in the worker thread
        self.worker_thread.start()

    def kill_thread(self):
        # Just tell the worker to stop, then tell it to quit and wait for that
        # to happen
        self.worker_thread.requestInterruption()
        if self.worker_thread.isRunning():
            self.worker_thread.quit()
            self.worker_thread.wait()
        else:
            print('worker has already exited.')

    def force_quit(self):
        # For use when the window is closed
        if self.worker_thread.isRunning():
            self.kill_thread()

    # The functions below update the UI and run in the main thread because
    # that's where the slots are set up

    @Slot(str, logging.LogRecord)
    def update_status(self, status, record):
        color = self.COLORS.get(record.levelno, 'black')
        s = '<pre><font color="%s">%s</font></pre>' % (color, status)
        self.textedit.appendHtml(s)

    @Slot()
    def manual_update(self):
        # This function uses the formatted message passed in, but also uses
        # information from the record to format the message in an appropriate
        # color according to its severity (level).
        level = random.choice(LEVELS)
        extra = {'qThreadName': ctname() }
        logger.log(level, 'Manually logged!', extra=extra)

    @Slot()
    def clear_display(self):
        self.textedit.clear()


def main():
    QtCore.QThread.currentThread().setObjectName('MainThread')
    logging.getLogger().setLevel(logging.DEBUG)
    app = QtWidgets.QApplication(sys.argv)
    example = Window(app)
    example.show()
    if hasattr(app, 'exec'):
        rc = app.exec()
    else:
        rc = app.exec_()
    sys.exit(rc)

if __name__=='__main__':
    main()

گزارش‌گیری در syslog با پشتیبانی از RFC5424

اگرچه RFC 5424 به سال ۲۰۰۹ بازمی‌گردد، بیشتر کارگزارهای syslog به‌طور پیش‌فرض برای استفاده از RFC 3164 قدیمی‌تر پیکربندی شده‌اند، که به سال ۲۰۰۱ بازمی‌گردد. هنگامی که logging در سال ۲۰۰۳ به پایتون افزوده شد، از پروتکل پیشین (و تنها پروتکل موجود) در آن زمان پشتیبانی می‌کرد. از زمان انتشار RFC 5424، از آنجا که پیاده‌سازی گسترده‌ای از آن در کارگزارهای syslog صورت نگرفته است، قابلیت SysLogHandler به‌روزرسانی نشده است.

RFC 5424 شامل برخی ویژگی‌های مفید مانند پشتیبانی از داده‌های ساختاریافته است، و اگر نیاز دارید بتوانید به یک سرور syslog که از آن پشتیبانی می‌کند گزارش بفرستید، می‌توانید این کار را با یک هندلری زیرکلاس‌شده که چیزی شبیه به این است، انجام دهید:

import datetime as dt
import logging.handlers
import re
import socket
import time

class SysLogHandler5424(logging.handlers.SysLogHandler):

    tz_offset = re.compile(r'([+-]\d{2})(\d{2})$')
    escaped = re.compile(r'([\]"\\])')

    def __init__(self, *args, **kwargs):
        self.msgid = kwargs.pop('msgid', None)
        self.appname = kwargs.pop('appname', None)
        super().__init__(*args, **kwargs)

    def format(self, record):
        version = 1
        asctime = dt.datetime.fromtimestamp(record.created).isoformat()
        m = self.tz_offset.match(time.strftime('%z'))
        has_offset = False
        if m and time.timezone:
            hrs, mins = m.groups()
            if int(hrs) or int(mins):
                has_offset = True
        if not has_offset:
            asctime += 'Z'
        else:
            asctime += f'{hrs}:{mins}'
        try:
            hostname = socket.gethostname()
        except Exception:
            hostname = '-'
        appname = self.appname or '-'
        procid = record.process
        msgid = '-'
        msg = super().format(record)
        sdata = '-'
        if hasattr(record, 'structured_data'):
            sd = record.structured_data
            # This should be a dict where the keys are SD-ID and the value is a
            # dict mapping PARAM-NAME to PARAM-VALUE (refer to the RFC for what these
            # mean)
            # There's no error checking here - it's purely for illustration, and you
            # can adapt this code for use in production environments
            parts = []

            def replacer(m):
                g = m.groups()
                return '\\' + g[0]

            for sdid, dv in sd.items():
                part = f'[{sdid}'
                for k, v in dv.items():
                    s = str(v)
                    s = self.escaped.sub(replacer, s)
                    part += f' {k}="{s}"'
                part += ']'
                parts.append(part)
            sdata = ''.join(parts)
        return f'{version} {asctime} {hostname} {appname} {procid} {msgid} {sdata} {msg}'

You'll need to be familiar with RFC 5424 to fully understand the above code, and it may be that you have slightly different needs (e.g. for how you pass structural data to the log). Nevertheless, the above should be adaptable to your specific needs. With the above handler, you'd pass structured data using something like this:

sd = {
    'foo@12345': {'bar': 'baz', 'baz': 'bozz', 'fizz': r'buzz'},
    'foo@54321': {'rab': 'baz', 'zab': 'bozz', 'zzif': r'buzz'}
}
extra = {'structured_data': sd}
i = 1
logger.debug('Message %d', i, extra=extra)

چگونه با یک گزارش‌گیر مانند یک جریان خروجی رفتار کنیم

گاهی اوقات، نیاز دارید با یک API شخص ثالث ارتباط برقرار کنید که انتظار دارد یک شیء شبه‌پرونده برای نوشتن در آن دریافت کند، اما می‌خواهید خروجی API را به یک گزارش‌گیر هدایت کنید. می‌توانید این کار را با استفاده از کلاسی که یک گزارش‌گیر را با یک API شبه‌پرونده دربر می‌گیرد، انجام دهید. در ادامه یک اسکریپت کوتاه آمده است که چنین کلاسی را نشان می‌دهد:

import logging

class LoggerWriter:
    def __init__(self, logger, level):
        self.logger = logger
        self.level = level

    def write(self, message):
        if message != '\n':  # avoid printing bare newlines, if you like
            self.logger.log(self.level, message)

    def flush(self):
        # doesn't actually do anything, but might be expected of a file-like
        # object - so optional depending on your situation
        pass

    def close(self):
        # doesn't actually do anything, but might be expected of a file-like
        # object - so optional depending on your situation. You might want
        # to set a flag so that later calls to write raise an exception
        pass

def main():
    logging.basicConfig(level=logging.DEBUG)
    logger = logging.getLogger('demo')
    info_fp = LoggerWriter(logger, logging.INFO)
    debug_fp = LoggerWriter(logger, logging.DEBUG)
    print('An INFO message', file=info_fp)
    print('A DEBUG message', file=debug_fp)

if __name__ == "__main__":
    main()

هنگامی که این اسکریپت اجرا می‌شود، چاپ می‌کند

INFO:demo:An INFO message
DEBUG:demo:A DEBUG message

همچنین می‌توانید با انجام کاری مانند این، از LoggerWriter برای تغییر مسیر sys.stdout و sys.stderr استفاده کنید:

import sys

sys.stdout = LoggerWriter(logger, logging.INFO)
sys.stderr = LoggerWriter(logger, logging.WARNING)

شما باید این کار را پس از پیکربندی گزارش‌گیری برای نیازهای خود انجام دهید. در مثال بالا، فراخوانی basicConfig() این کار را انجام می‌دهد (با استفاده از مقدار sys.stderr پیش از آنکه توسط یک نمونه از LoggerWriter بازنویسی شود). سپس، نتیجه‌ای از این دست دریافت خواهید کرد:

>>> print('Foo')
INFO:demo:Foo
>>> print('Bar', file=sys.stderr)
WARNING:demo:Bar
>>>

البته، مثال‌های بالا خروجی را مطابق قالب مورد استفاده‌ی basicConfig() نشان می‌دهند، اما شما می‌توانید هنگام پیکربندی گزارش‌گیری از یک قالب‌بند (formatter) متفاوت استفاده کنید.

توجه داشته باشید که با روش بالا، تا حدی تحت رحمت بافرینگ (buffering) و ترتیب فراخوانی‌های write که آن‌ها را رهگیری می‌کنید، هستید. برای مثال، با تعریف LoggerWriter در بالا، اگر قطعه‌کد زیر را داشته باشید

sys.stderr = LoggerWriter(logger, logging.WARNING)
1 / 0

سپس اجرای اسکریپت منجر می‌شود به

WARNING:demo:Traceback (most recent call last):

WARNING:demo:  File "/home/runner/cookbook-loggerwriter/test.py", line 53, in <module>

WARNING:demo:
WARNING:demo:main()
WARNING:demo:  File "/home/runner/cookbook-loggerwriter/test.py", line 49, in main

WARNING:demo:
WARNING:demo:1 / 0
WARNING:demo:ZeroDivisionError
WARNING:demo::
WARNING:demo:division by zero

همان‌طور که می‌بینید، این خروجی ایده‌آل نیست. دلیل آن این است که کد زیرساختی که در sys.stderr می‌نویسد، چندین عملیات نوشتن انجام می‌دهد که هر یک به یک خط گزارش‌شده جداگانه منجر می‌شود (برای مثال، سه خط آخر بالا). برای رفع این مشکل، باید داده‌ها را بافر کنید و سطرهای گزارش را تنها زمانی که نویسه‌های خط جدید دیده می‌شوند خروجی دهید. بیایید از یک پیاده‌سازی کمی بهتر از LoggerWriter استفاده کنیم:

class BufferingLoggerWriter(LoggerWriter):
    def __init__(self, logger, level):
        super().__init__(logger, level)
        self.buffer = ''

    def write(self, message):
        if '\n' not in message:
            self.buffer += message
        else:
            parts = message.split('\n')
            if self.buffer:
                s = self.buffer + parts.pop(0)
                self.logger.log(self.level, s)
            self.buffer = parts.pop()
            for part in parts:
                self.logger.log(self.level, part)

این کار فقط داده‌ها را تا مشاهده‌ی یک خط جدید بافر می‌کند و سپس سطرهای کامل را ثبت می‌کند. با این روش، خروجی بهتری دریافت می‌کنید:

WARNING:demo:Traceback (most recent call last):
WARNING:demo:  File "/home/runner/cookbook-loggerwriter/main.py", line 55, in <module>
WARNING:demo:    main()
WARNING:demo:  File "/home/runner/cookbook-loggerwriter/main.py", line 52, in main
WARNING:demo:    1/0
WARNING:demo:ZeroDivisionError: division by zero

چگونه سطرهای جدید را در خروجی گزارش به‌طور یکنواخت مدیریت کنیم

معمولاً پیام‌هایی که گزارش می‌شوند (مثلاً در کنسول یا پرونده) از یک خط متن تشکیل شده‌اند. با این حال، گاهی نیاز است پیام‌هایی با چند خط مدیریت شوند — خواه به این دلیل که رشته قالب گزارش شامل نویسه‌های خط جدید باشد، خواه داده گزارش‌شده شامل نویسه‌های خط جدید باشد. اگر می‌خواهید چنین پیام‌هایی را به‌صورت یکنواخت مدیریت کنید، به‌طوری که هر خط در پیام گزارش‌شده به‌صورت یکنواخت قالب‌بندی‌شده به نظر برسد، گویی جداگانه گزارش شده است، می‌توانید این کار را با استفاده از یک میکس‌این هندلر (handler mixin) انجام دهید، همان‌طور که در قطعه کد زیر آمده است:

# Assume this is in a module mymixins.py
import copy

class MultilineMixin:
    def emit(self, record):
        s = record.getMessage()
        if '\n' not in s:
            super().emit(record)
        else:
            lines = s.splitlines()
            rec = copy.copy(record)
            rec.args = None
            for line in lines:
                rec.msg = line
                super().emit(rec)

می‌توانید از میکس‌این مانند اسکریپت زیر استفاده کنید:

import logging

from mymixins import MultilineMixin

logger = logging.getLogger(__name__)

class StreamHandler(MultilineMixin, logging.StreamHandler):
    pass

if __name__ == '__main__':
    logging.basicConfig(level=logging.DEBUG, format='%(asctime)s %(levelname)-9s %(message)s',
                        handlers = [StreamHandler()])
    logger.debug('Single line')
    logger.debug('Multiple lines:\nfool me once ...')
    logger.debug('Another single line')
    logger.debug('Multiple lines:\n%s', 'fool me ...\ncan\'t get fooled again')

این اسکریپت، هنگام اجرا، چیزی شبیه به این را چاپ می‌کند:

2025-07-02 13:54:47,234 DEBUG     Single line
2025-07-02 13:54:47,234 DEBUG     Multiple lines:
2025-07-02 13:54:47,234 DEBUG     fool me once ...
2025-07-02 13:54:47,234 DEBUG     Another single line
2025-07-02 13:54:47,234 DEBUG     Multiple lines:
2025-07-02 13:54:47,234 DEBUG     fool me ...
2025-07-02 13:54:47,234 DEBUG     can't get fooled again

اگر، از سوی دیگر، نگران تزریق گزارش (log injection) هستید، می‌توانید از قالب‌بند (formatter) استفاده کنید که نویسه‌های خط جدید را خنثی می‌کند، مطابق مثال زیر:

import logging

logger = logging.getLogger(__name__)

class EscapingFormatter(logging.Formatter):
    def format(self, record):
        s = super().format(record)
        return s.replace('\n', r'\n')

if __name__ == '__main__':
    h = logging.StreamHandler()
    h.setFormatter(EscapingFormatter('%(asctime)s %(levelname)-9s %(message)s'))
    logging.basicConfig(level=logging.DEBUG, handlers = [h])
    logger.debug('Single line')
    logger.debug('Multiple lines:\nfool me once ...')
    logger.debug('Another single line')
    logger.debug('Multiple lines:\n%s', 'fool me ...\ncan\'t get fooled again')

البته می‌توانید از هر روش خنثی‌سازی که برای شما مناسب‌تر است استفاده کنید. اسکریپت، هنگام اجرا، باید خروجی‌ای مانند این تولید کند:

2025-07-09 06:47:33,783 DEBUG     Single line
2025-07-09 06:47:33,783 DEBUG     Multiple lines:\nfool me once ...
2025-07-09 06:47:33,783 DEBUG     Another single line
2025-07-09 06:47:33,783 DEBUG     Multiple lines:\nfool me ...\ncan't get fooled again

رفتار خنثی‌کردن نمی‌تواند پیش‌فرض کتابخانه استاندارد باشد، زیرا سازگاری با نسخه‌های پیشین را نقض می‌کند.

الگوهایی که باید از آن‌ها اجتناب کرد

اگرچه بخش‌های پیشین روش‌هایی برای انجام کارهایی که ممکن است لازم باشد انجام دهید یا با آن‌ها سروکار داشته باشید را شرح داده‌اند، اما ذکر برخی الگوهای استفاده که غیرمفید هستند و بنابراین در بیشتر موارد باید از آن‌ها اجتناب شود، ارزشمند است. بخش‌های زیر ترتیب خاصی ندارند.

باز کردن چندباره‌ی همان پرونده گزارش

در ویندوز، معمولاً نمی‌توانید همان پرونده را چندین بار باز کنید، زیرا این کار منجر به خطای «file is in use by another process» می‌شود. با این حال، در پلتفرم‌های POSIX اگر همان پرونده را چندین بار باز کنید، هیچ خطایی دریافت نخواهید کرد. این کار ممکن است به‌صورت تصادفی انجام شود، برای مثال با:

• افزودن هندلر پرونده (file handler) بیش از یک بار که به همان پرونده ارجاع می‌دهد (مثلاً بر اثر خطای کپی/چسباندن/فراموشی تغییر).

• باز کردن دو پرونده‌ای که متفاوت به نظر می‌رسند، زیرا نام‌های متفاوتی دارند، اما یکسان هستند، چون یکی از آن‌ها پیوند نمادین به دیگری است.

• انشعاب (forking) یک فرایند، که پس از آن هر دو والد و فرزند به یک پرونده ارجاع دارند. این ممکن است برای مثال از طریق استفاده از ماژول multiprocessing رخ دهد.

باز کردن یک پرونده چندین بار ممکن است به نظر برسد که بیشتر مواقع کار می‌کند، اما می‌تواند در عمل به تعدادی مشکل منجر شود:

• خروجی گزارش‌گیری ممکن است به‌هم‌ریخته شود، زیرا چندین نخ یا فرایند سعی می‌کنند در یک پرونده مشترک بنویسند. اگرچه گزارش‌گیری در برابر استفاده‌ی همزمان چندین نخ از یک نمونه‌ی هندلر یکسان محافظت می‌کند، اما اگر دو نخ متفاوت با استفاده از دو نمونه‌ی هندلری متفاوت که اتفاقاً به یک پرونده مشترک اشاره می‌کنند، اقدام به نوشتن همزمان کنند، چنین محافظتی وجود ندارد.

• تلاش برای حذف یک پرونده (مثلاً هنگام چرخش پرونده) بی‌صدا شکست می‌خورد، زیرا ارجاع دیگری به آن اشاره می‌کند. این موضوع می‌تواند به سردرگمی و هدر رفتن زمان اشکال‌زدایی منجر شود — ورودی‌های گزارش در مکان‌های غیرمنتظره‌ای قرار می‌گیرند، یا به‌کلی از بین می‌روند. یا پرونده‌ای که قرار بود جابه‌جا شود، در جای خود باقی می‌ماند و با وجود اینکه چرخش مبتنی بر اندازه ظاهراً برقرار است، اندازه‌اش به‌طور غیرمنتظره‌ای افزایش می‌یابد.

برای اجتناب از چنین مشکلاتی، از روش‌های شرح‌داده‌شده در گزارش‌گیری در یک پرونده واحد از چندین فرآیند استفاده کنید.

استفاده از گزارش‌گیرها به‌عنوان ویژگی در یک کلاس یا ارسال آن‌ها به‌عنوان پارامتر

اگرچه ممکن است موارد غیرمعمولی وجود داشته باشد که به انجام این کار نیاز داشته باشید، اما به‌طور کلی دلیلی برای این کار وجود ندارد، زیرا گزارش‌گیرها تک‌نمونه هستند. کد همیشه می‌تواند با استفاده از logging.getLogger(name) از طریق نام به نمونه گزارش‌گیر موردنظر دسترسی پیدا کند، بنابراین جابه‌جایی نمونه‌ها و نگه‌داشتن آن‌ها به‌عنوان ویژگی‌های نمونه بی‌فایده است. توجه داشته باشید که در زبان‌های دیگر مانند Java و C#، گزارش‌گیرها اغلب ویژگی‌های static کلاس هستند. با این حال، این الگو در پایتون معنایی ندارد، جایی که ماژول (و نه کلاس) واحد تجزیه نرم‌افزاری است.

افزودن هندلرهایی غیر از NullHandler به یک گزارش‌گیر در یک کتابخانه

پیکربندی گزارش‌گیری با افزودن هندلرها، قالب‌بندها و فیلترها، بر عهده توسعه‌دهنده برنامه است، نه توسعه‌دهنده کتابخانه. اگر در حال نگهداری یک کتابخانه هستید، اطمینان حاصل کنید که به هیچ‌یک از گزارش‌گیرهای خود هندلری اضافه نمی‌کنید، مگر یک نمونه از NullHandler.

ایجاد تعداد زیادی گزارش‌گیر

گزارش‌گیرها تک‌نمونه‌هایی هستند که هرگز در طول اجرای یک اسکریپت آزاد نمی‌شوند، بنابراین ایجاد تعداد زیادی گزارش‌گیر حافظه‌ای را مصرف می‌کند که سپس نمی‌توان آن را آزاد کرد. به‌جای ایجاد یک گزارش‌گیر به‌ازای مثلاً هر پرونده پردازش‌شده یا هر اتصال شبکه‌ای که برقرار می‌شود، از مکانیزم‌های موجود برای انتقال اطلاعات زمینه‌ای به گزارش‌هایتان استفاده کنید و گزارش‌گیرهای ایجادشده را به آن‌هایی که بخش‌هایی درون برنامه‌تان را توصیف می‌کنند محدود کنید (معمولاً ماژول‌ها، اما گاهی کمی ریزدانه‌تر از آن).

منابع دیگر

همچنین ملاحظه نمائید

ماژول logging

مرجع API ماژول logging.

ماژول logging.config

API پیکربندی ماژول logging.

ماژول logging.handlers

هندلرهای مفید ارائه‌شده همراه با ماژول logging.

خودآموز مقدماتی

آموزش پیشرفته