threading и logging. Как логировать в несколько потоков?

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

В общем и целом, штудировал я и интернет, и исследовал на практике этот вопрос. Странным оказалось то, что готового решения я не нашел, неужели никто не испытывает проблем с этим? Никто в python не пишет логи?

Начну по порядку и сразу к делу, без дифирамбов.

logging

В python есть замечательный инструмент для работы с логами, ниже листинг простейшей программы:

import logging
import sys

logger = logging.getLogger(__name__)
if not logger.hasHandlers():
    logger.setLevel(logging.DEBUG)
    stream = logging.StreamHandler(stream=sys.stdout)
    file = logging.FileHandler('logs.log')
    stream.setLevel(logging.DEBUG)
    file.setLevel(logging.DEBUG)
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    stream.setFormatter(formatter)
    file.setFormatter(formatter)
    logger.addHandler(stream)
    logger.addHandler(file)
    logger.set_handler = True

logger.info('This is a log message')

В этом коде я собрал всё, что мне удалось нарыть в интернете по моей проблеме:

1. Как одновременно стримить логи в консоль и в файл.

2. Как ограничить количество хэндлеров для одного экземпляра logger.

3. Как задать формат для логов.

threading

В python есть возможность исполнять программу в многопоточном режиме (ну, или в псевдомногопоточном, кому как нравится), ниже листинг простейшего применения этого модуля:

import threading
import time


def main():
    time.sleep(5)


thread = threading.Thread(target=main)
thread.start()
thread.join()

Выполнение функции main() в многопоточном режиме в контексте логирования будет выглядеть так:

import logging
import sys
import threading
import time


def main(n: int):
    logger = logging.getLogger(threading.current_thread().name)
    logger.setLevel(logging.DEBUG)
    stream = logging.StreamHandler(stream=sys.stdout)
    file = logging.FileHandler(f'logs_{threading.current_thread().name}.log')
    stream.setLevel(logging.DEBUG)
    file.setLevel(logging.DEBUG)
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    stream.setFormatter(formatter)
    file.setFormatter(formatter)
    logger.addHandler(stream)
    logger.addHandler(file)
    logger.info(f'This is a log message from {n}')
    time.sleep(1)

    
threads = []
for i in range(5):
    thread = threading.Thread(target=main, args=(i,))
    with open(f'logs_{thread.name}.log', 'w') as f:
        f.write('')
    thread.start()
    threads.append(thread)

for thread in threads:
    thread.join()  # wait for all threads to finish
    

Казалось бы, что еще нужно? Все работает прекрасно и на потоки делится. Но не все так гладко становится, когда нужно логировать работу экземпляров класса.

threading в контексте logging и ООП

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

Есть два пути решения проблемы. Первый - передавать в метод ссылку на экземпляр logging.Logger, а второй - переместить код с настройкой logger в родительский класс.

Листинг классов, которые будут использоваться для логирования и многопоточности:

import logging
import sys
import threading
import time


class YoungPerson:
    def __init__(self):
        self.age = 35


class User(YoungPerson):
    def __init__(self):
        super().__init__()
        self.name = None

    def set_name(self, new_name, logger):
        logger = logging.getLogger(threading.current_thread().name)
        logger.setLevel(logging.DEBUG)
        stream = logging.StreamHandler(stream=sys.stdout)
        file = logging.FileHandler(f'logs_{threading.current_thread().name}.log')
        stream.setLevel(logging.DEBUG)
        file.setLevel(logging.DEBUG)
        formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
        stream.setFormatter(formatter)
        file.setFormatter(formatter)
        logger.addHandler(stream)
        logger.addHandler(file)
        logger.info(f"{self.name} changed name to {new_name}")
        self.name = new_name
        time.sleep(1)
        

Давайте попробуем передать в метод set_name() ссылку на экземпляр логгера и получим следующий код:

import logging
import threading

import youngPersons

young_persons = [youngPersons.User() for _ in range(10)]

threads = []
for user in young_persons:
    thread = threading.Thread(target=user.set_name, args=('John',))
    logger = logging.getLogger(thread.name)
    thread.start()
    threads.append(thread)

for thread in threads:
    thread.join()  # wait for all threads to finish

Но здесь возникает проблема: мы не можем передать название потока еще до того, как поток был проинициализирован (см. строки кода 10-11).

Значит первый вариант решения проблемы не подходит, остается второй. А так будет выглядеть код с классами, если перенести настройку логов в родительский класс:

import logging
import sys
import time


class YoungPerson:
    def __init__(self):
        self.age = 35
        self.logger = logging.getLogger(__name__)

    def set_logger_name(self, logger_name):
        self.logger = logger_name
        if not self.logger.hasHandlers():
            self.logger.setLevel(logging.DEBUG)
            stream = logging.StreamHandler(stream=sys.stdout)
            file = logging.FileHandler(f'logs_{self.logger.name}.log')
            stream.setLevel(logging.DEBUG)
            file.setLevel(logging.DEBUG)
            formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
            stream.setFormatter(formatter)
            file.setFormatter(formatter)
            self.logger.addHandler(stream)
            self.logger.addHandler(file)
            self.logger.set_handler = True


class User(YoungPerson):
    def __init__(self):
        super().__init__()
        self.name = None

    def set_name(self, new_name):
        time.sleep(1)
        self.logger.info(f"{self.name} changed name to {new_name}")
        self.name = new_name

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

import logging
import threading
import youngPersons


young_persons = [youngPersons.User() for _ in range(10)]

threads = []

for user in young_persons:
    thread = threading.Thread(target=user.set_name, args=('John',))
    logger = logging.getLogger(thread.name)
    user.set_logger_name(logger_name=logger)
    with open(f'logs_{thread.name}.log', 'w') as f:
        f.write('')
    thread.start()
    threads.append(thread)

for thread in threads:
    thread.join()  # wait for all threads to finish

Теперь для каждого потока создается свой логгер, а хендлеры добавляются уже позже, в родительском классе.

Плюсы такого решения в том, что есть возможность задавать произвольное число потоков. Для этого нужно дополнительно создать класс, который будет работать с группами экземпляров класса User, и алгоритм, который будет делить объекты по группам.

Но это уже другая история.. Если хотите, чтобы я ее раскрыл, то поддержите меня, как автора на Хабр. Очень буду рад вашим комментариям и с большой охотой на них отвечу.

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