因为涉及到进程间互斥与通信问题，因此默认情况下Python中的logging无法在多进程环境下打印日志。但是查询了官方文档可以发现，推荐了一种利用logging.SocketHandler的方案来实现多进程日志打印。
其原理很简单，概括一句话就是说：多个进程将各自环境下的日志通过Socket发送给一个专门打印日志的进程，这样就可以防止多进程打印的冲突与混乱情况。
本文主要记录下SocketHandler真实的用法情况：
1 时序图
简单说明下逻辑：主进程（MainProcess）启动一个专门打印日志的进程（LogReceiverProcess），并且将自己（主进程）环境下的日志都“重定向”给LogReceiverProcess。同理，在后续逻辑中启动的所有工作子进程（WorkerProcess）都做一样的操作，把自己环境下的日志都“重定向”给日志进程去打印。
2 实现代码
2.1 日志进程
日志进程的代码核心在于要建立一个TCP Server来接收并处理Log record，代码如下：
import os
import logging
import logging.handlers
import traceback
import cPickle
import struct
import SocketServer
from multiprocessing import Process class LogRecordStreamHandler(SocketServer.StreamRequestHandler):
def handle(self):
while True:
try:
chunk = self.connection.recv(4)
if len(chunk) < 4:
break
slen = struct.unpack(">L", chunk)[0]
chunk = self.connection.recv(slen)
while len(chunk) < slen:
chunk = chunk + self.connection.recv(slen - len(chunk))
obj = self.unpickle(chunk)
record = logging.makeLogRecord(obj)
self.handle_log_record(record) except:
break @classmethod
def unpickle(cls, data):
return cPickle.loads(data) def handle_log_record(self, record):
if self.server.logname is not None:
name = self.server.logname
else:
name = record.name
logger = logging.getLogger(name)
logger.handle(record) class LogRecordSocketReceiver(SocketServer.ThreadingTCPServer):
allow_reuse_address = 1 def __init__(self, host='localhost', port=logging.handlers.DEFAULT_TCP_LOGGING_PORT, handler=LogRecordStreamHandler):
SocketServer.ThreadingTCPServer.__init__(self, (host, port), handler)
self.abort = 0
self.timeout = 1
self.logname = None def serve_until_stopped(self):
import select
abort = 0
while not abort:
rd, wr, ex = select.select([self.socket.fileno()], [], [], self.timeout)
if rd:
self.handle_request()
abort = self.abort def _log_listener_process(log_format, log_time_format, log_file):
log_file = os.path.realpath(log_file)
logging.basicConfig(level=logging.DEBUG, format=log_format, datefmt=log_time_format, filename=log_file, filemode='a+') # Console log
console = logging.StreamHandler()
console.setLevel(logging.INFO)
console.setFormatter(logging.Formatter(fmt=log_format, datefmt=log_time_format))
logging.getLogger().addHandler(console) tcp_server = LogRecordSocketReceiver() logging.debug('Log listener process started ...')
tcp_server.serve_until_stopped()
关键点：
（1）TCPServer的构建逻辑，拆包还原Log记录；
（2）在日志进程中设定好logging记录级别和打印方式，这里除了指定文件存储还添加了Console打印。
2.2 其他进程
除了日志进程之外的进程，设置logging都“重定向”给日志进程，并且要关闭当前进程的日志在Console打印（默认会显示Warning级别及以上的日志到Console），否则Console上日志展示会有重复凌乱的感觉。
class LogHelper:
# 默认日志存储路径（相对于当前文件路径）
default_log_path = os.path.join(os.path.dirname(os.path.realpath(__file__)), '..', 'logs') # 记录当前实际的日志所在目录
current_log_path = '' # 记录当前实际的日志完整路径
current_log_file = '' # 日志文件内容格式
log_format = '[%(asctime)s.%(msecs)03d][%(processName)s][%(levelname)s][%(filename)s:%(lineno)d] %(message)s' # 日志中时间格式
log_time_format = '%Y%m%d %H:%M:%S' # 日志进程
log_process = None def __init__(self):
pass @staticmethod
def print_console_log(level, message):
print '--------------------------------------------------'
if level == logging.WARN:
level_str = '[WARN]'
elif level == logging.ERROR:
level_str = '[ERROR]'
elif level == logging.FATAL:
level_str = '[FATAL]'
else:
level_str = '[INFO]'
print '\t%s %s' % (level_str, message)
print '--------------------------------------------------' @staticmethod
def init(clear_logs=True, log_path=''):
#
console = logging.StreamHandler()
console.setLevel(logging.FATAL)
logging.getLogger().addHandler(console) try:
# 如果外部没有指定日志存储路径则默认在common同级路径存储
if log_path == '':
log_path = LogHelper.default_log_path
if not os.path.exists(log_path):
os.makedirs(log_path)
LogHelper.current_log_path = log_path # 清理旧的日志并初始化当前日志路径
if clear_logs:
LogHelper.clear_old_log_files()
LogHelper.current_log_file = LogHelper._get_latest_log_file() socket_handler = logging.handlers.SocketHandler('localhost', logging.handlers.DEFAULT_TCP_LOGGING_PORT)
logging.getLogger().setLevel(logging.DEBUG)
logging.getLogger().addHandler(socket_handler) #
LogHelper.start() except Exception, ex:
LogHelper.print_console_log(logging.FATAL, 'init() exception: %s' % str(ex))
traceback.print_exc() @staticmethod
def start():
if LogHelper.log_process is None:
LogHelper.log_process = Process(target=_log_listener_process, name='LogRecorder', args=(LogHelper.log_format, LogHelper.log_time_format, LogHelper.current_log_file))
LogHelper.log_process.start()
else:
pass @staticmethod
def stop():
if LogHelper.log_process is None:
pass
else:
LogHelper.log_process.terminate()
LogHelper.log_process.join() @staticmethod
def _get_latest_log_file():
latest_log_file = ''
try:
if os.path.exists(LogHelper.current_log_path):
for maindir, subdir, file_name_list in os.walk(LogHelper.current_log_path):
for file_name in file_name_list:
apath = os.path.join(maindir, file_name)
if apath > latest_log_file:
latest_log_file = apath if latest_log_file == '':
latest_log_file = LogHelper.current_log_path + os.sep + 'system_'
latest_log_file += time.strftime("%Y%m%d_%H%M%S", time.localtime(time.time())) + '.log' except Exception, ex:
logging.error('EXCEPTION: %s' % str(ex))
traceback.print_exc() finally:
return latest_log_file @staticmethod
def get_log_file():
return LogHelper.current_log_file @staticmethod
def clear_old_log_files():
if not os.path.exists(LogHelper.current_log_path):
logging.warning('clear_old_log_files() Not exist: %s' % LogHelper.current_log_path)
return try:
for maindir, subdir, file_name_list in os.walk(LogHelper.current_log_path):
for file_name in file_name_list:
apath = os.path.join(maindir, file_name)
if apath != LogHelper.current_log_file:
logging.info('DEL -> %s' % str(apath))
os.remove(apath)
else:
with open(LogHelper.current_log_file, 'w') as f:
f.write('') logging.debug('Clear log done.') except Exception, ex:
logging.error('EXCEPTION: %s' % str(ex))
traceback.print_exc()