Блокировка регистрации получения и освобождения вызовов в многопоточном приложении

Question

Я пытаюсь отладить многопоточное приложение Python, которое использует различные блокировки.

Вместо того, чтобы помещать log.debug (...) операторов по всему кадру, чтобы отследить, где и когда блокировки получены и освобождены, моя идея состоит в том, чтобы украсить методы threading.Lock .acquire () и threading.Lock.release () и добавьте к их вызову следующий код:

log.debug("lock::acquire() [%s.%s.%s]" %
          (currentThread().getName(),
           self.__class__.__name__,
           sys._getframe().f_code.co_name))

Где log - некоторый глобальный logging объект - для обсуждения.

Теперь в идеале имя "lock" в записи журнала должно быть получено во время выполнения, так что независимо от того, какой объект блокировки вызывается при регистрации в журнале, будет выводиться его имя, декорированная операция, текущий поток, класс и функция, в которой вызывается операция (acqu | release).

Отказ от ответственности : Я признаю, что приведенный выше код не будет достаточным для любой такой реализации декоратора. Это только для того, чтобы дать представление о том, чего, я думаю, можно достичь.

Кто-нибудь знает, могу ли я украсить стандартные методы библиотеки, не исцеляя исходный код библиотеки threading , т. Е. Из моего вызывающего кода приложения?

Возможно, я лаю не на том дереве, и есть лучший способ достичь тех же целей без использования декораторов? Заранее большое спасибо за любые рекомендации, если это действительно так.

Решение: (вдохновленный лазыром)

Следующий код регистрирует операции блокировки и дает мне имя метода / функции, вызывающей операцию блокировки (я также адаптирую код для работы с Условиями и их дополнительными wait () и notify () методы):

# Class to wrap Lock and simplify logging of lock usage
class LogLock(object):
    """
    Wraps a standard Lock, so that attempts to use the
    lock according to its API are logged for debugging purposes

    """
    def __init__(self, name, log):
        self.name = str(name)
        self.log = log
        self.lock = threading.Lock()
        self.log.debug("{0} created {1}".format(
            inspect.stack()[1][3], self.name))

    def acquire(self, blocking=True):
        self.log.debug("{0} trying to acquire {1}".format(
            inspect.stack()[1][3], self.name))
        ret = self.lock.acquire(blocking)
        if ret == True:
            self.log.debug("{0} acquired {1}".format(
                inspect.stack()[1][3], self.name))
        else:
            self.log.debug("{0} non-blocking acquire of {1} lock failed".format(
                inspect.stack()[1][3], self.name))
        return ret

    def release(self):
        self.log.debug("{0} releasing {1}".format(inspect.stack()[1][3], self.name))
        self.lock.release()

    def __enter__(self):
        self.acquire()

    def __exit__(self, exc_type, exc_val, exc_tb):
        self.release()
        return False # Do not swallow exceptions

Где экземпляр журнала передан в LogLock. init был определен с logging.Formatter следующим образом, чтобы дать мне идентификатор вызывающего потока:

# With the following format
log_format = \
        logging.Formatter('%(asctime)s %(levelname)s %(threadName)s %(message)s')

Answer 1

У меня недавно была только ваша проблема.Я настроил свой регистратор на автоматическое логирование имени потока, как в этом ответе.Я обнаружил, что невозможно создать подкласс Lock, поэтому мне пришлось обернуть его следующим образом:

class LogLock(object):
    def __init__(self, name):
        self.name = str(name)
        self.lock = Lock()

    def acquire(self, blocking=True):
        log.debug("{0:x} Trying to acquire {1} lock".format(
            id(self), self.name))
        ret = self.lock.acquire(blocking)
        if ret == True:
            log.debug("{0:x} Acquired {1} lock".format(
                id(self), self.name))
        else:
            log.debug("{0:x} Non-blocking aquire of {1} lock failed".format(
                id(self), self.name))
        return ret

    def release(self):
        log.debug("{0:x} Releasing {1} lock".format(id(self), self.name))
        self.lock.release()

    def __enter__(self):
        self.acquire()

    def __exit__(self, exc_type, exc_val, exc_tb):
        self.release()
        return False    # Do not swallow exceptions

Я зарегистрировал идентификатор объекта, чтобы я мог различать несколько замков с одним и тем же именем, выможет не понадобиться.