OpenStack 实现技术分解 (6) 通用库 — oslo_log

文件夹

前文列表

OpenStack 实现技术分解 (1) 开发环境 — Devstack 部署案例具体解释
OpenStack 实现技术分解 (2) 虚拟机初始化工具 — Cloud-Init & metadata & userdata
OpenStack 实现技术分解 (3) 开发工具 — VIM & dotfiles
OpenStack 实现技术分解 (4) 通用技术 — TaskFlow
OpenStack 实现技术分解 (5) 应用开发 — 使用 OpenStackClients 进行二次开发

扩展阅读

Usage — oslo.log 3.21.1.dev1 documentation
oslo.log – Oslo Logging Library

日志级别

在记录日志时, 须要将日志消息关联一个级别, 系统默认提供了 6 个级别，它们各自是：

critical > error > warning > info > debug > notset

级别越高打印的日志越少，反之亦然:

  • DEBUG: 打印全级别日志( notset 等同于 debug)
  • INFO: 打印 info/warning/error/critical 级别日志
  • WARNING: 打印 warning/error/critical 级别日志
  • ERROR: 打印 error/critical 级别日志
  • CRITICAL: 打印 critical 级别

一般而言, 在程序的开发阶段会打印大量的日志, 此时的日志级别应为 DEBUG. 直到程序稳定后, 为了提高程序的运行效率, 须要打印日志应该相对降低. 依据实际情况, 可能会删减 DEBUG 级别的日志代码. 此时, 程序猿更关心的是跟踪用户的动作, 比如: 用户对于核心数据的改动动作就很有必要记录在案, 所以可以选择 INFO 及以上级别的日志, 当中最重要的信息就应该选择 CRITICAL 级别了. 须要注意的是, 异常捕获代码块(try-except)中都应该使用 ERROR/EXCEPTION(由 oslo_log 提供的异常栈级别) 级别的日志, 以便定位具体的错误原因.

oslo.log

(摘自官方文档)The oslo.log (logging) configuration library provides standardized configuration for all openstack projects. It also provides custom formatters, handlers and support for context specific logging (like resource id’s etc).

oslo.log(logging) 库为所有的 OpenStack 项目提供了标准的日志处理方式, 它还提供能自己定义日志格式以及各种 handlers, 同一时候也支持指定上下文对象的日志, 比如: resource_id 的日志等等.

实际上 oslo_log 是基于 Python’s standard logging library 标准库的封装, 在总体使用的简易性上得到了提升.

初始化设置 DEMO

from oslo_config import cfg
from oslo_log import log as logging

LOG = logging.getLogger(__name__)
CONF = cfg.CONF
DOMAIN = "demo"

logging.register_options(CONF)
logging.setup(CONF, DOMAIN)

# Oslo Logging uses INFO as default
LOG.info("Oslo Logging")
LOG.warning("Oslo Logging")
LOG.error("Oslo Logging")

显然的, 为了充分利用 oslo_conf 的跨文件作用域特性, oslo_log 通常会与 oslo_conf 结合使用, 由 oslo_conf 为 oslo_log 提供项目的日志配置项參数值. 对于 oslo_log 而言, 配置项引入是一个很重要且具有实践价值的设计理念.

oslo.log 的相关配置项

各个配置项的含义在凝视中也作了清晰的介绍:

################
# From oslo.log
################

# If set to true, the logging level will be set to DEBUG instead of the default
# INFO level. (boolean value)
# Note: This option can be changed without restarting.
debug = true

# DEPRECATED: If set to false, the logging level will be set to WARNING instead
# of the default INFO level. (boolean value)
# This option is deprecated for removal.
# Its value may be silently ignored in the future.
#verbose = true

# The name of a logging configuration file. This file is appended to any
# existing logging configuration files. For details about logging configuration
# files, see the Python logging module documentation. Note that when logging
# configuration files are used then all logging configuration is set in the
# configuration file and other logging configuration options are ignored (for
# example, logging_context_format_string). (string value)
# Note: This option can be changed without restarting.
# Deprecated group/name - [DEFAULT]/log_config
#log_config_append = <None>

# Defines the format string for %%(asctime)s in log records. Default:
# %(default)s . This option is ignored if log_config_append is set. (string
# value)
#log_date_format = %Y-%m-%d %H:%M:%S

# (Optional) Name of log file to send logging output to. If no default is set,
# logging will go to stderr as defined by use_stderr. This option is ignored if
# log_config_append is set. (string value)
# Deprecated group/name - [DEFAULT]/logfile
#log_file = <None>

# (Optional) The base directory used for relative log_file  paths. This option
# is ignored if log_config_append is set. (string value)
# Deprecated group/name - [DEFAULT]/logdir
#log_dir = <None>

# Uses logging handler designed to watch file system. When log file is moved or
# removed this handler will open a new log file with specified path
# instantaneously. It makes sense only if log_file option is specified and
# Linux platform is used. This option is ignored if log_config_append is set.
# (boolean value)
#watch_log_file = false

# Use syslog for logging. Existing syslog format is DEPRECATED and will be
# changed later to honor RFC5424. This option is ignored if log_config_append
# is set. (boolean value)
#use_syslog = false

# Syslog facility to receive log lines. This option is ignored if
# log_config_append is set. (string value)
#syslog_log_facility = LOG_USER

# Log output to standard error. This option is ignored if log_config_append is
# set. (boolean value)
#use_stderr = true

# Format string to use for log messages with context. (string value)
#logging_context_format_string = %(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [%(request_id)s %(user_identity)s] %(instance)s%(message)s

# Format string to use for log messages when context is undefined. (string
# value)
#logging_default_format_string = %(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [-] %(instance)s%(message)s

# Additional data to append to log message when logging level for the message
# is DEBUG. (string value)
#logging_debug_format_suffix = %(funcName)s %(pathname)s:%(lineno)d

# Prefix each line of exception output with this format. (string value)
#logging_exception_prefix = %(asctime)s.%(msecs)03d %(process)d ERROR %(name)s %(instance)s

# Defines the format string for %(user_identity)s that is used in
# logging_context_format_string. (string value)
#logging_user_identity_format = %(user)s %(tenant)s %(domain)s %(user_domain)s %(project_domain)s

# List of package logging levels in logger=LEVEL pairs. This option is ignored
# if log_config_append is set. (list value)
#default_log_levels = amqp=WARN,amqplib=WARN,boto=WARN,qpid=WARN,sqlalchemy=WARN,suds=INFO,oslo.messaging=INFO,iso8601=WARN,requests.packages.urllib3.connectionpool=WARN,urllib3.connectionpool=WARN,websocket=WARN,requests.packages.urllib3.util.retry=WARN,urllib3.util.retry=WARN,keystonemiddleware=WARN,routes.middleware=WARN,stevedore=WARN,taskflow=WARN,keystoneauth=WARN,oslo.cache=INFO,dogpile.core.dogpile=INFO

# Enables or disables publication of error events. (boolean value)
#publish_errors = false

# The format for an instance that is passed with the log message. (string
# value)
#instance_format = "[instance: %(uuid)s] "

# The format for an instance UUID that is passed with the log message. (string
# value)
#instance_uuid_format = "[instance: %(uuid)s] "

# Enables or disables fatal status of deprecations. (boolean value)
#fatal_deprecations = false

对于有 Python logging 标准库使用经验的程序猿而言, 应该很easy的就能体会到 oslo_log 对 logging 进行封装后带来的优点. 以往使用 logging 时须要在代码中显式定义的状态信息(e.g. 日志级别/打印格式/handler 等), 如今都可以通过 oslo_log 配置文件的配置项參数值来简化定义. 有效的避免了在程序中写出很多无谓的代码, 并且通过阅读配置文件可以更清晰的理解当前程序的日志状态.

一般来说我们须要关心的 oslo_log 配置项有下面几个:

  • debug = true: 是否将日志级别设定为 DEBUG
  • verbose = true: 将日志级别设定为 INFO(true) 还是 WARNING(false)
  • log_date_format = %Y-%m-%d %H:%M:%S: 日志的日期格式
  • log_file = <None>: 日志文件名
  • log_dir = <None>: 日志文件路径
  • use_stderr = true: 是否让日志以 system standard error 管道输出
  • logging_context_format_string: 日志内容格式
  • default_log_levels: 相关程序的默认日志级别
  • instance_format: instance 的日志打印格式, 所谓的上下文对象日志

oslo_log 支持通过调用 logging 的 register_options() method 来实现配置项的注冊:

CONF = cfg.CONF

def prepare():

    # Required step to register common, logging and generic configuration
    # variables
    logging.register_options(CONF)

register_options method 会帮助我们将上述配置文件里的配置项以默认值注冊到 CONF 对象中:

logging.register_options(CONF)
>>> CONF.items()
[('default_log_levels', ['amqp=WARN', 'amqplib=WARN', 'boto=WARN', 'qpid=WARN', 'sqlalchemy=WARN', 'suds=INFO', 'oslo.messaging=INFO', 'iso8601=WARN', 'requests.packages.urllib3.connectionpool=WARN', 'urllib3.connectionpool=WARN', 'websocket=WARN', 'requests.packages.urllib3.util.retry=WARN', 'urllib3.util.retry=WARN', 'keystonemiddleware=WARN', 'routes.middleware=WARN', 'stevedore=WARN', 'taskflow=WARN', 'keystoneauth=WARN', 'oslo.cache=INFO', 'dogpile.core.dogpile=INFO']), ('verbose', True), ('watch_log_file', False), ('logging_default_format_string', '%(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [-] %(instance)s%(message)s'), ('use_stderr', False), ('log_date_format', '%Y-%m-%d %H:%M:%S'), ('rate_limit_burst', 0), ('logging_context_format_string', '%(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [%(request_id)s %(user_identity)s] %(instance)s%(message)s'), ('instance_format', '[instance: %(uuid)s] '), ('use_syslog', False), ('log_dir', None), ('publish_errors', False), ('logging_debug_format_suffix', '%(funcName)s %(pathname)s:%(lineno)d'), ('logging_exception_prefix', '%(asctime)s.%(msecs)03d %(process)d ERROR %(name)s %(instance)s'), ('syslog_log_facility', 'LOG_USER'), ('instance_uuid_format', '[instance: %(uuid)s] '), ('log_config_append', None), ('rate_limit_except_level', 'CRITICAL'), ('rate_limit_interval', 0), ('debug', False), ('log_file', None), ('logging_user_identity_format', '%(user)s %(tenant)s %(domain)s %(user_domain)s %(project_domain)s')]

所以我们在使用 oslo_log 时无需在程序代码中反复定义这些 options. 可以很方便的通过改动配置文件里配置项的值, 来实现对 oslo_log 的管理.
NOTE: 假设在运行了 logging.register_options(CONF) 之后, 又在程序中反复定义了这些重名配置项的话, 会触发异常:

slo_config.cfg.DuplicateOptError: duplicate option: debug

在注冊了配置项之后, 还可以通过调用 logging 的 setup() method 来指定该 logger 的作用域, 支持在一个程序中存在多个不同 domain 的 logger:

DOMAIN = 'demo'

def prepare():

    # Required setup based on configuration and domain
    logging.setup(CONF, DOMAIN)

同一时候, oslo_log 也支持使用 logging 的 set_defaults method 来动态改动日志级别:

    # Optional step to set new defaults if necessary for
    # * logging_context_format_string
    # * default_log_levels

    extra_log_level_defaults = [
        'dogpile=INFO',
        'routes=INFO'
        ]

    logging.set_defaults(
        default_log_levels=logging.get_default_log_levels() +
        extra_log_level_defaults)

上述的 3 个 method 让程序中日志的使用变得更加灵活.

oslo.log 的日志级别

oslo.log 经常使用的 5 个日志级及其相应的 function:

from oslo_log import log as logging

LOG = logging.getLogger(__name__)

LOG.debug("Some key is %s", "key")

LOG.info("Create something %s start", "test")

LOG.exception("Failed to create something %(something)s as error %(err)s", {"something": "something", "err": "err"})

LOG.error("Failed to create something")

LOG.cretical("Fatal error as %s", "fatal")

oslo.log 的使用技巧

一般而言, 我会建议程序中的日志宜多不宜少, 但在上文也有提到, 大量的日志会对程序运行效率造成影响, 所以理解怎样精准的在程序中的不同场景使用不同级别的日志就显得很有必要了.

推荐使用 LOG.debug 的地方

LOG.debug 一般用于对实參数据体准确度较为敏感的 function/method 语句块的首行, 让开发人员可以高速的推断是否得到了预期实參. 所以这里须要打印出 module_name & function_name/method_name & 实參值.
EXAMPLE 1: REST API controller method 中接收到的 request info:

def index(self, req):
    LOG.debug("Get server list with parameter %s,", req.GET())
    ...

EXAMPLE 2: 一些通过逻辑比較复杂的流程而得到的參数 

...
# 运行一次复杂的排序操作
sort_result = _complex_sort(arr)
LOG.debug("Front list %(fro)s change to %(now)s after complex_sort.", {'fro': arr, 'now': sort_result})
...

推荐使用 LOG.info 的地方

LOG.info 一般用于标记业务逻辑步骤, 让运维/开发人员都可以高速推断程序流到了哪一个步, 所以这里须要打印 module_name & step_description & 业务对象的唯一标示

EXAMPLE: 当运行一个所需步骤大于等于二的程序流程时, 须要打印程序流開始到结束的过程

...
LOG.info("Create server %s start.", server.id)
...
LOG.info("Prepare image for server %s.", server.id)
...
LOG.info("Prepare network for server %s", server.id)
...
LOG.info("Create server %s successful", server.id)
...

推荐使用 LOG.exception 的地方

LOG.exception/LOG.error 一般用于 try-except 异常捕获语句块, 假设捕获到的是某一个准确的异常可以使用 LOG.error, 假设捕获的是某一类异常或所有异常时可以使用 LOG.exception 来打印出异常栈.

EXAMPLE: 在暴露的 RPC API 或者 HTTP API 方法中增加 exception 级别日志

def index(self, req):
    ...
    try:
        self.server_api.get_all_servers()
    except Exception as err:
        LOG.exception("Failed to get servers as error %s", six.text_type(err))
        raise exc.HTTPInnevalError()
    ...

推荐使用 LOG.error 的地方

EXAMPLE: 同上, 但假设程序流没有再上一层的调用时, 也可以使用LOG.error, 由于已经不须要打印异常栈了.

try:
    # do something
    ...
except Exception as err:
    LOG.error("Failed to do something as error %s", six.text_type(err))
    raise

推荐使用 LOG.cretical 的地方

LOG.cretical 一般用于当错误可能会导致程序进程崩溃等极其严重的逻辑块中

try:
    # 运行一些危急操作
    ...
except Exception as err:
    LOG.cretical("Failed to do something as error %s", six.text_type(err))
    raise
posted on 2017-08-18 08:27  ljbguanli  阅读(1386)  评论(0)  编辑  收藏  举报

Powered by: 博客园 Copyright © 2024 ljbguanli
Powered by .NET 9.0 on Kubernetes