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

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

Меня попросили посмотреть на код и показать, как можно выводить документацию для каждого метода в лог. В python это лучше всего сделать с помощью декораторов. Декораторы – это мощная штука! В общем, меньше слов и больше кода.

import logging

def method_decorator(func):
    def wrapper(self, *argv, **kwargv):
        logging.basicConfig(filename='myapp.log', level=logging.INFO)
        logging.info(func.__doc__)
        return func(self, *argv, **kwargv)
    return wrapper

class Something1(object):

    @method_decorator
    def method1(self):
        """documentation thru method decorator for method 1"""
        pass

    def method2(self):
        """documentation thru method decorator for method 2"""
        pass

    @method_decorator
    def method3(self):
        """documentation thru method decorator for method 3"""
        pass

s1 = Something1()
s1.method1()
s1.method2()
s1.method3()

# or thru class decorator

def class_decorator(cls):
    for name, method in cls.__dict__.iteritems():
        if not name.startswith('_'):
            setattr(cls, name, method_decorator(method))
    return cls

@class_decorator
class Something2(object):

    def method1(self):
        """documentation thru class decorator for method 1"""
        pass

    def method2(self):
        """documentation thru class decorator for method 2"""
        pass

    def method3(self):
        """documentation thru class decorator for method 3"""
        pass

s2 = Something2()
s2.method1()
s2.method2()
s2.method3()

#check mixed execution
s1.method1()
s2.method1()

Т.е. мы описываем необходимый читабельный комментарий как docstring для методов, и когда эти методы вызываются, в лог записывается читабельная информация. В первом случае, можно использовать декоратор для методов, который можно использовать по требованию. А второй класс показывает, как можно включить данное логирование для всех методов класса. Или же Вы можете задать любую необходимую вам логику в class_decorator().

Вот, что мы получаем в логе:

INFO:root:documentation thru method decorator for method 1
INFO:root:documentation thru method decorator for method 3
INFO:root:documentation thru class decorator for method 1
INFO:root:documentation thru class decorator for method 2
INFO:root:documentation thru class decorator for method 3
INFO:root:documentation thru method decorator for method 1
INFO:root:documentation thru class decorator for method 1

Ну а теперь давайте подключим это к каким-то юнит-тестам. Например, это может выглядеть так.

import logging
import unittest
import random
from functools import wraps

def method_decorator(func):
    @wraps(func)
    def wrapper(self, *argv, **kwargv):
        logging.basicConfig(filename='myapp.log', 
            level=logging.INFO, format='%(message)s')
        logging.info("\t- %s" % func.__doc__)
        return func(self, *argv, **kwargv)
    return wrapper

def class_decorator(cls):
    for name, method in cls.__dict__.iteritems():
        if not name.startswith('_'):
            setattr(cls, name, method_decorator(method))
    return cls

class MyTestingException(Exception):

    def __init__(self, value):
        self.msg = value

    def __str__(self):
        return "%s\n%s" % (self.msg, open("myapp.log").read())

@class_decorator
class Something(object):

    def _generate_number(self):
        if random.randint(0, 10) == 5:
            raise MyTestingException("Please have a look to details:")
        return random.randint(0, 2)

    def method1(self):
        """log to system to make some actions"""
        return self._generate_number()

    def method2(self):
        """registered account with additional credits"""
        return self._generate_number()

    def method3(self):
        """buy subscription for defined account"""
        return self._generate_number()

class TestSomething(unittest.TestCase):

    def setUp(self):
        with open("myapp.log", "w") as f:
            f.truncate()
        self.s = Something()
        self.data = {'some data': [1, 2, 3]}

    def test_method1(self):
        self.s.method1()
        self.s.method2()
        self.s.method3()
        self.assertEquals(self.s.method1(), 0)

    def test_method2(self):
        self.s.method3()
        self.s.method2()
        self.s.method1()
        self.assertEquals(self.s.method2(), 1)

    def test_method3(self):
        self.s.method1()
        self.s.method3()
        self.s.method2()
        self.assertEquals(self.s.method3(), 2)

if __name__ == '__main__':
    unittest.main()

Что дает следующие результаты:

EFE

======================================================================

ERROR: test_method1 (__main__.TestSomething)

----------------------------------------------------------------------

Traceback (most recent call last):

  File "demo.py", line 64, in test_method1

    self.s.method3()

  File "demo.py", line 12, in wrapper

    return func(self, *argv, **kwargv)

  File "demo.py", line 50, in method3

    return self._generate_number()

  File "demo.py", line 37, in _generate_number

    raise MyTestingException("Please have a look to details:")

MyTestingException: Please have a look to details:

	- log to system to make some actions

	- registered account with additional credits

	- buy subscription for defined account

======================================================================

ERROR: test_method3 (__main__.TestSomething)

----------------------------------------------------------------------

Traceback (most recent call last):

  File "demo.py", line 77, in test_method3

    self.assertEquals(self.s.method3(), 2)

  File "demo.py", line 12, in wrapper

    return func(self, *argv, **kwargv)

  File "demo.py", line 50, in method3

    return self._generate_number()

  File "demo.py", line 37, in _generate_number

    raise MyTestingException("Please have a look to details:")

MyTestingException: Please have a look to details:

	- log to system to make some actions

	- buy subscription for defined account

	- registered account with additional credits

	- buy subscription for defined account

======================================================================

FAIL: test_method2 (__main__.TestSomething)

----------------------------------------------------------------------

Traceback (most recent call last):

  File "demo.py", line 71, in test_method2

    self.assertEquals(self.s.method2(), 1)

AssertionError: 2 != 1

----------------------------------------------------------------------

Ran 3 tests in 0.003s

FAILED (failures=1, errors=2)

Как всегда, пишите, если у Вас есть вопросы! Удачи и хорошего Вам питонирования!