详解Python logging调用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)

 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

 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

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

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

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')

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)

 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

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

 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)

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

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__