我正在研究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
非标准手动线程选项效果最佳,因为没有日志模块的开销,但显然您会错过许多功能,如格式化程序、过滤器和良好的界面。 单线程中的std_logging是次佳选择,但仍比非标准手动线程慢约3倍。 std_manual_threading选项将消息转储到线程安全队列中,并在单独的线程中使用标准日志记录模块。这大约比第二个选项高25%,可能是由于上下文切换成本造成的。 最后,使用“logutils”的QueueHandler选项是最昂贵的。我调整了logutils / queue.py的_monitor方法的代码,在处理500个消息后睡眠10毫秒,只要队列中的消息少于100K,就可以将运行时间从7秒降至5秒(可能是由于避免上下文切换成本造成的)。
我的问题是,为什么日志记录模块存在如此多的性能开销?是否有任何替代方案?作为一个性能敏感的应用程序,使用日志记录模块甚至有意义吗? P.S.:我已经对不同的情况进行了分析,似乎LogRecord的创建很耗费资源。