Я изучаю высокопроизводительные протоколирования в Python и до сих пор разочарован работой стандартного модуля протоколирования python, но, похоже, альтернатив нет. Ниже приведен фрагмент кода для теста производительности. 4 разных способа ведения журнала:
import logging
import timeit
import time
import datetime
from logutils.queue import QueueListener, QueueHandler
import Queue
import threading
tmpq = Queue.Queue()
def std_manual_threading():
start = datetime.datetime.now()
logger = logging.getLogger()
hdlr = logging.FileHandler('std_manual.out', 'w')
logger.addHandler(hdlr)
logger.setLevel(logging.DEBUG)
def logger_thread(f):
while True:
item = tmpq.get(0.1)
if item == None:
break
logging.info(item)
f = open('manual.out', 'w')
lt = threading.Thread(target=logger_thread, args=(f,))
lt.start()
for i in range(100000):
tmpq.put("msg:%d" % i)
tmpq.put(None)
lt.join()
print datetime.datetime.now() - start
def nonstd_manual_threading():
start = datetime.datetime.now()
def logger_thread(f):
while True:
item = tmpq.get(0.1)
if item == None:
break
f.write(item+"\n")
f = open('manual.out', 'w')
lt = threading.Thread(target=logger_thread, args=(f,))
lt.start()
for i in range(100000):
tmpq.put("msg:%d" % i)
tmpq.put(None)
lt.join()
print datetime.datetime.now() - start
def std_logging_queue_handler():
start = datetime.datetime.now()
q = Queue.Queue(-1)
logger = logging.getLogger()
hdlr = logging.FileHandler('qtest.out', 'w')
ql = QueueListener(q, hdlr)
# Create log and set handler to queue handle
root = logging.getLogger()
root.setLevel(logging.DEBUG) # Log level = DEBUG
qh = QueueHandler(q)
root.addHandler(qh)
ql.start()
for i in range(100000):
logging.info("msg:%d" % i)
ql.stop()
print datetime.datetime.now() - start
def std_logging_single_thread():
start = datetime.datetime.now()
logger = logging.getLogger()
hdlr = logging.FileHandler('test.out', 'w')
logger.addHandler(hdlr)
logger.setLevel(logging.DEBUG)
for i in range(100000):
logging.info("msg:%d" % i)
print datetime.datetime.now() - start
if __name__ == "__main__":
"""
Conclusion: std logging about 3 times slower so for 100K lines simple file write is ~1 sec while std
logging ~3. If threads are introduced some overhead causes to go to ~4 and if QueueListener and events
are used with enhancement for thread sleeping that goes to ~5 (probably because log records are being
inserted into queue).
"""
print "Testing"
#std_logging_single_thread() # 3.4
std_logging_queue_handler() # 7, 6, 7 (5 seconds with sleep optimization)
#nonstd_manual_threading() # 1.08
#std_manual_threading() # 4.3
- Опция nonstd_manual_threading работает лучше всего, так как нет накладных расходов на модуль регистрации, но, очевидно, вы пропустите множество функций, таких как форматирование, фильтры и приятный интерфейс.
- std_logging в одном потоке - это следующая лучшая вещь, но все же примерно в 3 раза медленнее, чем ручная нарезка nonstd.
- Параметр std_manual_threading отправляет сообщения в очередь потокобезопасности, а в отдельном потоке использует стандартный модуль ведения журнала. Это выходит примерно на 25% выше, чем вариант 2, возможно, из-за затрат на коммутацию контекста.
- Наконец, опция, использующая "logutils" QueueHandler, оказывается самой дорогой. Я изменил код метода logutils/queue.py _monitor для сна в течение 10 миллисекунд после обработки 500 сообщений, если в очереди осталось менее 100K сообщений. Это сокращает время выполнения от 7 секунд до 5 секунд (возможно, из-за отсутствия затрат на коммутацию контекста).
Мой вопрос: почему в модуле регистрации есть так много служебных накладных расходов и есть ли альтернативы? Как приложение, чувствительное к производительности, имеет смысл использовать модуль регистрации?
p.s.: Я профилировал различные сценарии и, похоже, создание LogRecord дорого.
