Регистрация нескольких файлов Python

Question

У меня проблема с модулем журналирования Python, я не уверен, что я делаю что-то глупое, но у меня есть два скрипта Python, один (master.py), который вызывает другой (slave.py). Они оба регистрируются в отдельных файлах журнала, но второй вызываемый скрипт (slave.py), похоже, ведет рекурсивный журнал!

Кто-нибудь может увидеть, что я здесь делаю не так?

Вот мой код:

# master.py

import sys
import logging
import slave

masterLog = logging.getLogger('master')
masterLog.setLevel(logging.DEBUG)
masterHandler = logging.FileHandler('master.log')
formatter = logging.Formatter('%(levelname)s: %(asctime)s %(funcName)s(%(lineno)d) -- %(message)s', datefmt = '%Y-%m-%d %H:%M:%S')
masterHandler.setFormatter(formatter)
masterLog.addHandler(masterHandler)
masterLog.info('This is masterLog running on master.py')
print 'master.py has: ', len(masterLog.handlers), 'handlers'

for i in range(1,6):
      masterLog.info('Running slave %s' % i)
      slave.runMain()

---

# slave.py

import sys
import logging

def runMain():
    slaveLog = logging.getLogger('slave')
    slaveLog.setLevel(logging.DEBUG)
    slaveHandler = logging.FileHandler('slave.log')
    formatter = logging.Formatter('%(levelname)s: %(asctime)s %(funcName)s(%(lineno)d) -- %(message)s', datefmt = '%Y-%m-%d %H:%M:%S')
    slaveHandler.setFormatter(formatter)
    slaveLog.addHandler(slaveHandler)
    slaveLog.info('This is slaveLog running on slave.py')
    print 'slave.py has: ', len(slaveLog.handlers), 'handlers'

if __name__ == '__main__':
    runMain()

Вот вывод:

master.py has:  1 handlers
slave.py has:  1 handlers
slave.py has:  2 handlers
slave.py has:  3 handlers
slave.py has:  4 handlers
slave.py has:  5 handlers

И master.log:

INFO: 2012-02-29 13:26:49 <module>(13) -- This is masterLog running on master.py
INFO: 2012-02-29 13:26:49 <module>(17) -- Running slave 1
INFO: 2012-02-29 13:26:49 <module>(17) -- Running slave 2
INFO: 2012-02-29 13:26:49 <module>(17) -- Running slave 3
INFO: 2012-02-29 13:26:49 <module>(17) -- Running slave 4
INFO: 2012-02-29 13:26:49 <module>(17) -- Running slave 5

И раб.лог:

INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py
INFO: 2012-02-29 13:26:49 runMain(13) -- This is slaveLog running on slave.py

Кажется, что ведомый скрипт добавляет новый обработчик файлов при каждом вызове. В файле slave.log должно быть только 5 записей, но каждый раз, когда slave.py вызывается регистратором, выводится в каждый обработчик файлов!

Спасибо, Jak

Answer 1

logging.getLogger([name]) всегда возвращает один и тот же объект (глобальный объект), и вы вызываете addHandler для него каждый раз, когда вызываете runMain.

Answer 2

#!/usr/bin/env python
# -*- coding: utf-8 -*-

import logging
import logging.handlers
from logging.config import dictConfig

logger = logging.getLogger(__name__)

DEFAULT_LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
}
def configure_logging(logfile_path):
    """
    Initialize logging defaults for Project.

    :param logfile_path: logfile used to the logfile
    :type logfile_path: string

    This function does:

    - Assign INFO and DEBUG level to logger file handler and console handler

    """
    dictConfig(DEFAULT_LOGGING)

    default_formatter = logging.Formatter(
        "[%(asctime)s] [%(levelname)s] [%(name)s] [%(funcName)s():%(lineno)s] [PID:%(process)d TID:%(thread)d] %(message)s",
        "%d/%m/%Y %H:%M:%S")

    file_handler = logging.handlers.RotatingFileHandler(logfile_path, maxBytes=10485760,backupCount=300, encoding='utf-8')
    file_handler.setLevel(logging.INFO)

    console_handler = logging.StreamHandler()
    console_handler.setLevel(logging.DEBUG)

    file_handler.setFormatter(default_formatter)
    console_handler.setFormatter(default_formatter)

    logging.root.setLevel(logging.DEBUG)
    logging.root.addHandler(file_handler)
    logging.root.addHandler(console_handler)



[31/10/2015 22:00:33] [DEBUG] [yourmodulename] [yourfunction_name():9] [PID:61314 TID:140735248744448] this is logger infomation from hello module

Я думаю, вам лучше настроить формат ведения журнала в основной функции.