python

Как я писал свой логгер. Разбор ошибок

  • среда, 10 мая 2017 г. в 03:14:31
https://habrahabr.ru/post/328266/
  • Программирование
  • Отладка
  • Python


Относительно недавно я начал изучать Python. На чём бить шишки было непонятно, а делать упражнения ради упражнений наскучило достаточно быстро. Мне хотелось сделать что-то полезное и сделать это с энтузиазмом. Так родилась идея сделать логгер с цветным аутпутом. Проект был назван «SCLogger», начало было положено. Что получилось в итоге и какие ошибки при проектировании были допущены далее под катом.

Если у вас нет времени на прочтение, исходники можно найти тут.
Ссылка на исходники цветного аутпута.

Начало и первая ошибка


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

Перед тем, как писать код, я подумал «Каким логгер должен быть и что он должен уметь делать?». Ответ получился примерно такой…

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

  • Делать запись в файл
  • Выводить сообщение вместе с записью, если было указание на это
  • Выдавать статистику по количеству сообщений
  • Читать лог (весь; по типу сообщений)

И тут проявляется моя первая ошибка: не надо засовывать лишний функционал в класс. Лучше логически разграничивать обязанности по разным модулям/классам. Это полезно и для архитектуры, и для дальнейшей поддержки.

Тип ошибок логгера оставим самый стандартный и создадим его на базе Enum. Импортируем нужные нам модули и создаём 2 класса: Logger и MessageType, наследуемый от Enum.

from datetime import datetime
from pycolorize import colorize, cprint
from enum import Enum
import re  # позже прояснится

class MessageType(Enum):
    INFO = 10
    SUCCESS = 20
    WARNING = 30
    ERROR = 40
    CRITICAL = 50

# для сообщений я выбрал такие цвета
message_color = {
    'INFO': 'gray',
    'WARNING': 'yellow',
    'ERROR': 'red',
    'SUCCESS': 'cyan',
    'CRITICAL': 'magenta'
}

class Logger:
    def __init__(self, fp, delimiter=' ', protected_mode=False):
        if protected_mode:
            self.__file = open(fp, 'x')
        else:
            self.__file = open(fp, 'w')
        self.__delimiter = delimiter  # разделитель

        # Счётчик сообщений
        self.__data = {
            'INFO': 0,
            'WARNING': 0,
            'ERROR': 0,
            'SUCCESS': 0,
            'CRITICAL': 0
            }

Сейчас инициализация выглядит не так ужасно, как изначально. В первых версиях я допускал ошибку проектирования, указывая вместо protected_mode аргумент filemode. То есть я добавлял себе кучу работы, проверяя входит ли указанный filemode в допустимый кортеж. Так делать не надо, лучше упрощать по возможности.

Неожиданная встреча с ошибкой №2: бесполезный код.


Теперь напишем метод, который будет создавать сообщения. То есть главный функционал логгера:

    def message(self, message, message_type: MessageType, to_print=True, include_microseconds=False):
        mt = str(message_type).replace('MessageType.', '') 
                                                      # чтобы получить строку INFO, WARNING, etc.
                                                      # просто приводим к строке MessageType.TYPE
                                                      # и отсекаем ненужное
        date = datetime.today().date()
        if not include_microseconds:
            time = datetime.today().time().replace(microsecond=0)
        else:
            time = datetime.today().time()
        # выше мы собираем информацию для нашего сообщения

        self.__data[mt] += 1 # обновляем счётчик сообщений

        # создаём сообщение с помощью join
        message = self.__delimiter.join([str(date), str(time), message, mt])

        # пишем наше сообщение, убирая байты возможно окрашенных строк
        self.__file.write(re.sub(r'(\x1b\[.*?m)', '', message + '\n')) # тут нам нужен модуль re

        # делаем цветной print нашего сообщения с типизированным цветом
        if to_print:
            cprint(message, message_color[mt])

Всё бы хорошо, но что если я захочу проанализировать лог с помощью pandas, например? Для этого в первых версиях логгера у меня был метод __check_head, который я поместил в конец инициализации класса.

    def __check_head(self):
        template = self.__delimiter.join(['Date', 'Time', 'Message', 'Message type\n'])
        try:
            with open(self.__fp, 'r') as f: # старый атрибут, хранящий директорию
                if f.readlines()[0] != template:
                    self.__file.write(template)
        except IndexError:
            self.__file.write(template)

Это неправильный код. Эта ошибка порождена от самой первой: позволить выбрать пользователю filemode для работы с файлом. Почему метод выглядит так? Дело в том, что если файл открыт на дозапись (append), то нет необходимости писать шапку вновь, потому что файл будет некорректен. Поэтому необходимо было проверять файл на наличие шапки.

P.S. На самом деле до написания статьи я не обращал внимания на этот метод и аргумент __fp, и класс так и продолжал бы функционировать с плохим кодом, потому что и этот вариант рабочий, а я просто забыл его переписать.

Но сейчас логгер работает только в двух режимах: 'x' — уникальность файла и 'w' — создать файл или перезаписать уже существующий. Это изменение позволяет упросить код до такого вида:

    def __write_head(self):  # правильный код и более подходящее название для метода
        template = self.__delimiter.join(['Date', 'Time', 'Message', 'Message type\n'])
        self.__file.write(template)

Окончание работы и нахождение места для чтения сообщений


С первыми двумя пунктами покончили, даже сделали работу сверх него: добавили шапку. Пора реализовать получение статистики по количеству записанных сообщений. Создадим для этого метод get_stats:

    def get_stats(self):
        info = str(self.__data['INFO'])
        warning = str(self.__data['WARNING'])
        error = str(self.__data['ERROR'])
        success = str(self.__data['SUCCESS'])
        # собираем int по ключам из self.__data словаря приводим их к типу str

        # выводим данные, форматируя строку
        cprint('INFO MESSAGES COUNT: {}\n'
               'WARNING MESSAGES COUNT: {}\n'
               'ERROR MESSAGES COUNT: {}\n'
               'SUCCESS MESSAGES COUNT: {}'.format(
                            colorize(info, 'magenta'), colorize(warning, 'magenta'),
                            colorize(error, 'magenta'), colorize(success, 'magenta')), 'green')

Работа закончена, но меня не покидало желание сделать чтение сообщений, и я пытался прилепить метод read_messages() туда, куда не следовало (первая ошибка проектирования). В конце концов, я создал новый класс, который назвал LogReader:

class LogReader:
    def __init__(self, fp):
        self.__log = open(fp)

    def read_messages(self, message_type: MessageType=None):
        if message_type is None:
          # если мы не передали какой message type мы хотим считать
          # то мы будем искать с конца строки тип сообщения
          # а потом передавать его, как аргумент color для функции cprint()
            for line in self.__log.readlines()[1:]:
                line = line.strip()
                end = ''
                for char in line[::-1]:
                    if not char.isspace():
                        end += char
                    else:
                        end = end[::-1]
                        break
                try:
                    cprint(line.strip(), message_color[end])
                except KeyError:
                    cprint('Key not found. Add it to message_color dict in sclogger module', 'yellow') # тут идёт оповещение, если пользователь добавил свой ключ в тип сообщения
      # но не добавил для него цвет
                    cprint(line.strip())  # без аргументов будет стандартный вывод
        else:
            end = str(message_type).replace('MessageType.', '')
            for line in self.__log.readlines():
                line = line.strip()
                if line.endswith(end):
                    cprint(line.strip(), message_color[end])

Тестируя решение, я столкнулся с проблемой чтения: я забыл про то, что перед тем как файл открыть заново, его нужно закрыть. То есть если я в одном скрипте вызываю запись и чтение одного и того же лога, то чтение не происходит. Чтобы решить это, мне пришлось добавить метод close в класс Logger:

    def close(self):
        # закрываем файл, если необходимо
        self.__file.close()

Возможно, это не идеальное решение, но тем не менее всё получилось:

image

Подведём итоги.


Все ошибки так или иначе были связаны с проектированием. Шишки набиты и мораль усвоена. Ну и на всякий случай шпаргалка:

Что следует делать:

  • Упрощать — стройте простую архитектуру, пишите простой, легкочитаемый код.
  • После упрощения или перепроектирования делать рефакторинг сразу — не забывайте удалять ненужное, оптимизировать решения и улучшать читаемость кода.
  • Проектировать с умом и придерживаться архитектуры — как я уже говорил, стройте простую архитектуру, но не забывайте про то, что она должна быть логичной. После того, как вы решили, какой будет архитектура, не меняйте её без необходимости.
  • Разбивайте функционал — один класс или модуль под все задачи не всегда хорошо.
  • Задумывайтесь об интеграции — периодически задумывайтесь возможно ли и нужно ли, чтобы ваш проект мог работать/давать результат, интегрируемый в другие продукты.

Чего делать не следует:

  • Пытаться засунуть всё в один класс/модуль — если так хочется всё, то пускай это всё будет, но не сразу. Иногда хорошие идеи приходят спонтанно.
  • Допускать ошибки проектирования — старайтесь заранее обозначить как будет выглядеть ваш MVP (minimum viable product).
  • Оставлять рабочие, но бесполезные строки в коде — антоним второго пункта из предыдущего списка.

Спасибо за внимание!