Ведение журнала Python (имя функции, имя файла, номер строки) с использованием одного файла

109

Я пытаюсь узнать, как работает приложение. И для этого я вставляю команды отладки в качестве первой строки тела каждой функции с целью регистрации имени функции, а также номера строки (в коде), куда я отправляю сообщение в вывод журнала. Наконец, поскольку это приложение состоит из множества файлов, я хочу создать один файл журнала, чтобы лучше понимать поток управления приложения.

Вот что я знаю:

  1. для получения имени функции я могу использовать, function_name.__name__но не хочу использовать имя_функции (чтобы я мог быстро скопировать и вставить универсальный шаблон Log.info("Message")в тело всех функций). Я знаю, что это можно сделать на C с помощью __func__макроса, но я не уверен в питоне.

  2. для получения имени файла и номера строки я видел (и считаю, что) мое приложение использует locals()функцию Python, но в синтаксисе, о котором я не полностью осведомлен, например: options = "LOG.debug('%(flag)s : %(flag_get)s' % locals())и я пробовал использовать like, LOG.info("My message %s" % locals())который дает что-то вроде {'self': <__main__.Class_name object at 0x22f8cd0>}. Любые комментарии по этому поводу, пожалуйста?

  3. Я знаю, как использовать ведение журнала и добавить к нему обработчик для записи в файл, но я не уверен, можно ли использовать один файл для записи всех сообщений журнала в правильном порядке вызовов функций в проекте.

Буду очень признателен за любую помощь.

Спасибо!

user1126425
источник
Вы можете перейти в отладчик python с помощью import pdb; pdb.set_trace(), а затем выполнить код в интерактивном режиме. Это может помочь вам отслеживать выполнение программы.
Matthew Schinckel
Отличная идея! Спасибо, Мэтт. По-прежнему было бы полезно получить журнал, упомянутый в вопросе, чтобы мне не приходилось каждый раз отлаживать. Кроме того, знаете ли вы об IDE для python, которая не уступает Eclipse для Java (ctrl + click приводит вас к определению функции), которую я могу использовать, чтобы упростить отладку?
user1126425

Ответы:

28

У вас есть несколько второстепенных вопросов.

Начну с самого простого: (3). С loggingего помощью вы можете объединить все вызовы в один файл журнала или другую цель вывода: они будут в том порядке, в котором они произошли в процессе.

Далее: (2). locals()предоставляет информацию о текущей области. Таким образом, в методе, не имеющем других аргументов, у вас есть selfобласть, которая содержит ссылку на текущий экземпляр. Используемый трюк, который ставит вас в тупик, - это форматирование строки с использованием dict в качестве правой части %оператора. "%(foo)s" % barбудет заменен на любое значение bar["foo"].

Наконец, вы можете использовать некоторые уловки самоанализа, аналогичные тем, которые используются для pdbрегистрации дополнительной информации:

def autolog(message):
    "Automatically log the current function details."
    import inspect, logging
    # Get the previous frame in the stack, otherwise it would
    # be this function!!!
    func = inspect.currentframe().f_back.f_code
    # Dump the message + the name of this function to the log.
    logging.debug("%s: %s in %s:%i" % (
        message, 
        func.co_name, 
        func.co_filename, 
        func.co_firstlineno
    ))

Это будет регистрировать переданное сообщение плюс (исходное) имя функции, имя файла, в котором появляется определение, и строку в этом файле. Взгляните на inspect - Осмотрите живые объекты для получения более подробной информации.

Как я уже упоминал в своем комментарии ранее, вы также можете перейти в pdbинтерактивное приглашение отладки в любое время, вставив строку import pdb; pdb.set_trace()и повторно запустив свою программу. Это позволяет вам выполнять код, проверяя данные по своему усмотрению.

Мэтью Шинкель
источник
Спасибо, Мэтт! Я попробую эту функцию автолога. У меня есть небольшая путаница относительно использования dict в качестве RHS оператора%: Будет ли '%(foo)s : %(bar)s'также печататься значение bar["foo"]'s? Или это несколько отличается от вашего примера?
user1126425
По сути, все элементы формы %(<foo>)sзаменяются значением объекта, на который ссылается dict by <foo>. Больше примеров / подробностей можно найти
Мэтью Шинкель,
3
Ответ @synthesizerpatel намного полезнее.
Jan
505

Правильный ответ - использовать уже предоставленную funcNameпеременную

import logging
logger = logging.getLogger('root')
FORMAT = "[%(filename)s:%(lineno)s - %(funcName)20s() ] %(message)s"
logging.basicConfig(format=FORMAT)
logger.setLevel(logging.DEBUG)

Тогда куда угодно, просто добавьте:

logger.debug('your message') 

Пример вывода сценария, над которым я сейчас работаю:

[invRegex.py:150 -          handleRange() ] ['[A-Z]']
[invRegex.py:155 -     handleRepetition() ] [[<__main__.CharacterRangeEmitter object at 0x10ba03050>, '{', '1', '}']]
[invRegex.py:197 -          handleMacro() ] ['\\d']
[invRegex.py:155 -     handleRepetition() ] [[<__main__.CharacterRangeEmitter object at 0x10ba03950>, '{', '1', '}']]
[invRegex.py:210 -       handleSequence() ] [[<__main__.GroupEmitter object at 0x10b9fedd0>, <__main__.GroupEmitter object at 0x10ba03ad0>]]
синтезатор
источник
61
Это должен был быть ответ!
user3885927 04
1
Отлично .. Еще кое-что нужно добавить, можно ли динамически называть файл журнала таким же, как файл кода? например: я пробовал logging.basicConfig (filename = "% (filename)", format = FORMAT) динамически принимать имя файла, но он принимает статическое значение. любое предложение?
Outlier
2
@Outlier Нет, рекомендуемый способ добиться этогоgetLogger(__name__)
farthVader
2
У меня есть один вопрос: где-то на Java я читал, что печатать номер строки не рекомендуется, поскольку требуется дополнительное время, чтобы выяснить, из какой строки вызывается регистратор. В питоне это неправда?
McSonk 02
2
Неактуально, но logging.getLogger('root')это не то, что вы ожидаете, это не rootрегистратор, а обычный регистратор с именем root.
0xc0de
5

funcname, linenameИ linenoпредоставить информацию о последней функции , что сделали вырубку.

Если у вас есть оболочка регистратора (например, одноэлементный регистратор), то ответ @ synthesizerpatel может не сработать для вас.

Чтобы узнать других абонентов в стеке вызовов, вы можете:

import logging
import inspect

class Singleton(type):
    _instances = {}

    def __call__(cls, *args, **kwargs):
        if cls not in cls._instances:
            cls._instances[cls] = super(Singleton, cls).__call__(*args, **kwargs)
        return cls._instances[cls]

class MyLogger(metaclass=Singleton):
    logger = None

    def __init__(self):
        logging.basicConfig(
            level=logging.INFO,
            format="%(asctime)s - %(threadName)s - %(message)s",
            handlers=[
                logging.StreamHandler()
            ])

        self.logger = logging.getLogger(__name__ + '.logger')

    @staticmethod
    def __get_call_info():
        stack = inspect.stack()

        # stack[1] gives previous function ('info' in our case)
        # stack[2] gives before previous function and so on

        fn = stack[2][1]
        ln = stack[2][2]
        func = stack[2][3]

        return fn, func, ln

    def info(self, message, *args):
        message = "{} - {} at line {}: {}".format(*self.__get_call_info(), message)
        self.logger.info(message, *args)
SpiralDev
источник
1
Ваш ответ был именно тем, что мне нужно для решения моей проблемы. Спасибо.
Ошибка - Синтаксическое раскаяние
Начиная с Python 3.8, loggingкласс поддерживает пропуск на уровне стека «из коробки»: такие методы, как log(), debug()и т. Д., Теперь принимают stacklevelаргумент. См. Документы .
сломя голову