1. `Logger.info`源码:

def info(self, msg, *args, **kwargs):        """        Log 'msg % args' with severity 'INFO'.        To pass exception information, use the keyword argument exc_info with        a true value, e.g.        logger.info("Houston, we have a %s", "interesting problem", exc_info=1)        """        if self.isEnabledFor(INFO):            self._log(INFO, msg, args, **kwargs)

注释中反应了可以通过 msg和不定参数args来进行日志的格式化。

真实的调用为：_log方法：

2. `Logger._log`方法:

def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False):        """        Low-level logging routine which creates a LogRecord and then calls        all the handlers of this logger to handle the record.        """        sinfo = None        if _srcfile:            #IronPython doesn't track Python frames, so findCaller raises an            #exception on some versions of IronPython. We trap it here so that            #IronPython can use logging.            try:                fn, lno, func, sinfo = self.findCaller(stack_info)            except ValueError: # pragma: no cover                fn, lno, func = "(unknown file)", 0, "(unknown function)"        else: # pragma: no cover            fn, lno, func = "(unknown file)", 0, "(unknown function)"        if exc_info:            if isinstance(exc_info, BaseException):                exc_info = (type(exc_info), exc_info, exc_info.__traceback__)            elif not isinstance(exc_info, tuple):                exc_info = sys.exc_info()        record = self.makeRecord(self.name, level, fn, lno, msg, args,                                 exc_info, func, extra, sinfo)        self.handle(record)

最后两行：

生成日志记录：

record = self.makeRecord(self.name, level, fn, lno, msg, args, exc_info, func, extra, sinfo)

处理日志记录

self.handle(record)

2 生成日志记录:

def makeRecord(self, name, level, fn, lno, msg, args, exc_info,                   func=None, extra=None, sinfo=None):        """        A factory method which can be overridden in subclasses to create        specialized LogRecords.        """        rv = _logRecordFactory(name, level, fn, lno, msg, args, exc_info, func,                             sinfo)        if extra is not None:            for key in extra:                if (key in ["message", "asctime"]) or (key in rv.__dict__):                    raise KeyError("Attempt to overwrite %r in LogRecord" % key)                rv.__dict__[key] = extra[key]        return rv

调用_logRecordFactory初始化一个日志记录实例，_logRecordFactory 其实就是LogRecord类，初始化时，可能包含logger的name, level、调用的函数、行号、日志字符串、模板参数、堆栈信息等。

再看extra信息，extra到底有何用？现在从代码中可以看到，只是更新到生成的日志记录实例的__dict__中去.猜测：肯定会在生成最终的日志字符串的时候会用到。继续往下看。

3 处理日志记录`self.handle(record)`:

Logger继承自Filterer,

def handle(self, record):        """        Call the handlers for the specified record.        This method is used for unpickled records received from a socket, as        well as those created locally. Logger-level filtering is applied.        """        if (not self.disabled) and self.filter(record):            self.callHandlers(record)

3.1 if语句中有一self.filter(record)的判断，看函数名，是来筛选是否要继续处理消息的，其核心源码如下：

def filter(self, record):        """        Determine if a record is loggable by consulting all the filters.        The default is to allow the record to be logged; any filter can veto        this and the record is then dropped. Returns a zero value if a record        is to be dropped, else non-zero.        .. versionchanged:: 3.2           Allow filters to be just callables.        """        rv = True        for f in self.filters:            if hasattr(f, 'filter'):                result = f.filter(record)            else:                result = f(record) # assume callable - will raise if not            if not result:                rv = False                break        return rv

可以看到，如果在handler中的filter中如果有返回为False或空，则会屏蔽对应的record,返回True或部位空的值，则会将record放行。那么我们就可以自定义自己的filter。

3.2 让Logger中所有的handles去处理record:

def callHandlers(self, record):        """        Pass a record to all relevant handlers.        Loop through all handlers for this logger and its parents in the        logger hierarchy. If no handler was found, output a one-off error        message to sys.stderr. Stop searching up the hierarchy whenever a        logger with the "propagate" attribute set to zero is found - that        will be the last logger whose handlers are called.        """        c = self        found = 0        while c:            for hdlr in c.handlers:                found = found + 1                if record.levelno >= hdlr.level:                    hdlr.handle(record)            if not c.propagate:                c = None    #break out            else:                c = c.parent        if (found == 0):            if lastResort:                if record.levelno >= lastResort.level:                    lastResort.handle(record)            elif raiseExceptions and not self.manager.emittedNoHandlerWarning:                sys.stderr.write("No handlers could be found for logger"                                 " \"%s\"\n" % self.name)                self.manager.emittedNoHandlerWarning = True

代码中会去循环调用当前logger的所有handlers去处理record,for循环部分,之后，如果当前的logger的propagate的值为False或空，则不向logger的父logger传递，即向上传递。

4. `Handler` 中的 `handler(record)` 部分：

def handle(self, record):        """        Conditionally emit the specified logging record.        Emission depends on filters which may have been added to the handler.        Wrap the actual emission of the record with acquisition/release of        the I/O thread lock. Returns whether the filter passed the record for        emission.        """        rv = self.filter(record)        if rv:            self.acquire()            try:                self.emit(record)            finally:                self.release()        return rv

可以看到， Handler在处理record时，会去加锁，然后调用self.emit(record)方法去处理。

4.1 `emit(record)`

def emit(self, record):        """        Do whatever it takes to actually log the specified logging record.        This version is intended to be implemented by subclasses and so        raises a NotImplementedError.        """        raise NotImplementedError('emit must be implemented '                                  'by Handler subclasses')

看到需要由子类去实现，以StreamHandler为例子：

def emit(self, record):        """        Emit a record.        If a formatter is specified, it is used to format the record.        The record is then written to the stream with a trailing newline.  If        exception information is present, it is formatted using        traceback.print_exception and appended to the stream.  If the stream        has an 'encoding' attribute, it is used to determine how to do the        output to the stream.        """        try:            msg = self.format(record)            stream = self.stream            stream.write(msg)            stream.write(self.terminator)            self.flush()        except Exception:            self.handleError(record)

4.2 `Handler.format(record)`:

def format(self, record):        """        Format the specified record.        If a formatter is set, use it. Otherwise, use the default formatter        for the module.        """        if self.formatter:            fmt = self.formatter        else:            fmt = _defaultFormatter        return fmt.format(record)

如果handler有自定义的formatter就用自定义的，如果没有则用默认的Formatter的实例，初始化元源码为：

def __init__(self, fmt=None, datefmt=None, style='%'):        """        Initialize the formatter with specified format strings.        Initialize the formatter either with the specified format string, or a        default as described above. Allow for specialized date formatting with        the optional datefmt argument (if omitted, you get the ISO8601 format).        Use a style parameter of '%', '{' or '$' to specify that you want to        use one of %-formatting, :meth:`str.format` (``{}``) formatting or        :class:`string.Template` formatting in your format string.        .. versionchanged:: 3.2           Added the ``style`` parameter.        """        if style not in _STYLES:            raise ValueError('Style must be one of: %s' % ','.join(                             _STYLES.keys()))        self._style = _STYLES[style][0](fmt)        self._fmt = self._style._fmt        self.datefmt = datefmt

有三个参数：

fmt: 格式化模板

datefmt: 时间格式化参数

style: 日志格式化的样式。

style有三种：

_STYLES = {    '%': (PercentStyle, BASIC_FORMAT),    '{': (StrFormatStyle, '{levelname}:{name}:{message}'),    '$': (StringTemplateStyle, '${levelname}:${name}:${message}'),

可以看出对应到：% 操作符的格式化， format方法的格式化以及Template的格式化。

Formatter的format方法源码为：

def format(self, record):        """        Format the specified record as text.        The record's attribute dictionary is used as the operand to a        string formatting operation which yields the returned string.        Before formatting the dictionary, a couple of preparatory steps        are carried out. The message attribute of the record is computed        using LogRecord.getMessage(). If the formatting string uses the        time (as determined by a call to usesTime(), formatTime() is        called to format the event time. If there is exception information,        it is formatted using formatException() and appended to the message.        """        record.message = record.getMessage()        if self.usesTime():            record.asctime = self.formatTime(record, self.datefmt)        s = self.formatMessage(record)        if record.exc_info:            # Cache the traceback text to avoid converting it multiple times            # (it's constant anyway)            if not record.exc_text:                record.exc_text = self.formatException(record.exc_info)        if record.exc_text:            if s[-1:] != "\n":                s = s + "\n"            s = s + record.exc_text        if record.stack_info:            if s[-1:] != "\n":                s = s + "\n"            s = s + self.formatStack(record.stack_info)

看到会调用record.getMessage(),这里仅仅是获取我们需要的日志信息。

之后会调用s = self.formatMessage(record):

def formatMessage(self, record):        return self._style.format(record)

其实是调用了当前style的format方法，以%这一类型为例PercentStyle：

class PercentStyle(object):    default_format = '%(message)s'    asctime_format = '%(asctime)s'    asctime_search = '%(asctime)'    def __init__(self, fmt):        self._fmt = fmt or self.default_format    def usesTime(self):        return self._fmt.find(self.asctime_search) >= 0    def format(self, record):        return self._fmt % record.__dict__

从其中的format方法可以看出，是针对record的__dict__属性中的所有参数进行格式化，这下，就清楚了之前的extra参数是干嘛用的了：可以在formatter中加入自己自定义的一些参数，如固定的用户信息等等。

之后，将最终的message flush到对应的Stream里面去就行了，就是整个流程:

官方文档中的处理流程