摘要：中的部分可以看到，在處理時(shí)，會(huì)去加鎖，然后調(diào)用方法去處理。有三種可以看出對(duì)應(yīng)到操作符的格式化，方法的格式化以及的格式化。的方法源碼為看到會(huì)調(diào)用這里僅僅是獲取我們需要的日志信息。

本次分析一下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)

注釋中反應(yīng)了可以通過(guò) msg和不定參數(shù)args來(lái)進(jìn)行日志的格式化。
真實(shí)的調(diào)用為：_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)

    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

調(diào)用_logRecordFactory初始化一個(gè)日志記錄實(shí)例，_logRecordFactory 其實(shí)就是LogRecord類(lèi)，初始化時(shí)，可能包含logger的name, level、調(diào)用的函數(shù)、行號(hào)、日志字符串、模板參數(shù)、堆棧信息等。
再看extra信息，extra到底有何用？現(xiàn)在從代碼中可以看到，只是更新到生成的日志記錄實(shí)例的__dict__中去.猜測(cè)：肯定會(huì)在生成最終的日志字符串的時(shí)候會(huì)用到。繼續(xù)往下看。

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)

    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或空，則會(huì)屏蔽對(duì)應(yīng)的record,返回True或部位空的值，則會(huì)將record放行。那么我們就可以自定義自己的filter。

    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"
" % self.name)
                self.manager.emittedNoHandlerWarning = True

代碼中會(huì)去循環(huán)調(diào)用當(dāng)前logger的所有handlers去處理record,for循環(huán)部分,之后，如果當(dāng)前的logger的propagate的值為False或空，則不向logger的父logger傳遞，即向上傳遞。

    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時(shí)， 會(huì)去加鎖，然后調(diào)用self.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")

看到需要由子類(lèi)去實(shí)現(xiàn)，以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)

    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就用自定義的，如果沒(méi)有則用默認(rèn)的Formatter的實(shí)例， 初始化元源碼為：

    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

有三個(gè)參數(shù)：

fmt: 格式化模板

datefmt: 時(shí)間格式化參數(shù)

style: 日志格式化的樣式。

style有三種：

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

可以看出對(duì)應(yīng)到：% 操作符的格式化， 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:] != "
":
                s = s + "
"
            s = s + record.exc_text
        if record.stack_info:
            if s[-1:] != "
":
                s = s + "
"
            s = s + self.formatStack(record.stack_info)

看到會(huì)調(diào)用record.getMessage(),這里僅僅是獲取我們需要的日志信息。
之后會(huì)調(diào)用s = self.formatMessage(record):

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

其實(shí)是調(diào)用了當(dāng)前style的format方法，以%這一類(lèi)型為例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方法可以看出，是針對(duì)record的__dict__屬性中的所有參數(shù)進(jìn)行格式化，這下，就清楚了之前的extra參數(shù)是干嘛用的了：可以在formatter中加入自己自定義的一些參數(shù)，如固定的用戶(hù)信息等等。

之后，將最終的message flush到對(duì)應(yīng)的Stream里面去就行了，就是整個(gè)流程:

請(qǐng)大家多多指點(diǎn)。