当前位置:脚本大全 > > 正文

pythonlogging模块教学(详解Python logging调用Logger.info方法的处理过程)

时间:2022-03-30 20:14:36类别:脚本大全

pythonlogging模块教学

详解Python logging调用Logger.info方法的处理过程

本次分析一下logger.info的流程

1. logger.info源码:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 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方法:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16
  • 17
  • 18
  • 19
  • 20
  • 21
  • 22
  • 23
  • 24
  • 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)
  • 最后两行:

    生成日志记录:

  • ?
  • 1
  • record = self.makerecord(self.name, level, fn, lno, msg, args, exc_info, func, extra, sinfo)
  • 处理日志记录

  • ?
  • 1
  • self.handle(record)
  • 2 生成日志记录:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 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,

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 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)的判断,看函数名,是来筛选是否要继续处理消息的,其核心源码如下:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16
  • 17
  • 18
  • 19
  • 20
  • 21
  • 22
  • 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:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16
  • 17
  • 18
  • 19
  • 20
  • 21
  • 22
  • 23
  • 24
  • 25
  • 26
  • 27
  • 28
  • 29
  • 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) 部分:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16
  • 17
  • 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)

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 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为例子:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16
  • 17
  • 18
  • 19
  • 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):

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 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的实例, 初始化元源码为:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16
  • 17
  • 18
  • 19
  • 20
  • 21
  • 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
  • 有三个参数:

    style有三种:

  • ?
  • 1
  • 2
  • 3
  • 4
  • _styles = {
  •  '%': (percentstyle, basic_format),
  •  '{': (strformatstyle, '{levelname}:{name}:{message}'),
  •  '$': (stringtemplatestyle, '${levelname}:${name}:${message}'),
  • 可以看出对应到:% 操作符的格式化, format方法的格式化以及template的格式化。

    formatter的format方法源码为:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16
  • 17
  • 18
  • 19
  • 20
  • 21
  • 22
  • 23
  • 24
  • 25
  • 26
  • 27
  • 28
  • 29
  • 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):

  • ?
  • 1
  • 2
  • def formatmessage(self, record):
  •  return self._style.format(record)
  • 其实是调用了当前style的format方法,以%这一类型为例percentstyle:

  • ?
  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 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里面去就行了,就是整个流程:

    pythonlogging模块教学(详解Python logging调用Logger.info方法的处理过程)

    以上就是本文的全部内容,希望对大家的学习有所帮助,也希望大家多多支持开心学习网。

    原文链接:https://segmentfault.com/a/1190000018119406

    上一篇下一篇

    猜您喜欢

    热门推荐