使用elasticsearch-py进行日志记录

Question

我想记录我的 python 脚本，这个脚本使用了 elasticsearch-py。具体来说，我想要有三种日志：

1. 通用日志：记录 INFO 级别及以上的信息，既输出到 stdout（也就是终端）也保存到一个文件里。
2. ES日志：只记录与ES相关的信息，并且只保存到一个文件里。
3. ES追踪日志：扩展的ES日志（比如curl查询及其输出）也只保存到一个文件里。

这是我目前的代码：

import logging
import logging.handlers

es_logger = logging.getLogger('elasticsearch')
es_logger.setLevel(logging.INFO)
es_logger_handler=logging.handlers.RotatingFileHandler('top-camps-base.log',
                                                          maxBytes=0.5*10**9,
                                                          backupCount=3)
es_logger.addHandler(es_logger_handler)

es_tracer = logging.getLogger('elasticsearch.trace')
es_tracer.setLevel(logging.DEBUG)
es_tracer_handler=logging.handlers.RotatingFileHandler('top-camps-full.log',
                                                       maxBytes=0.5*10**9,
                                                       backupCount=3)
es_tracer.addHandler(es_tracer_handler)

logger = logging.getLogger('mainLog')
logger.setLevel(logging.DEBUG)
# create file handler
fileHandler = logging.handlers.RotatingFileHandler('top-camps.log',
                                                   maxBytes=10**6,
                                                   backupCount=3)
fileHandler.setLevel(logging.INFO)
# create console handler
consoleHandler = logging.StreamHandler()
consoleHandler.setLevel(logging.INFO)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
consoleHandler.setFormatter(formatter)
fileHandler.setFormatter(formatter)
# add the handlers to logger
logger.addHandler(consoleHandler)
logger.addHandler(fileHandler)

我的问题是，es_logger的 INFO 信息也显示在终端上。实际上，日志信息是正确保存到相应的文件里的！

如果我去掉与 logger 相关的部分，那么ES日志就正常工作了，也就是说只保存到对应的文件里。但这样我就没有其他的日志了……我在设置的最后部分做错了什么呢？

---

编辑

可能的提示：在 elasticsearch-py 的源代码中，有一个叫 logger 的记录器。会不会和我的冲突？我试着把上面的 logger 改成 main_logger，但没有帮助。

可能的提示2：如果我把 logger = logging.getLogger('mainLog') 替换成 logger = logging.getLogger()，那么 es_logger 输出到控制台的格式就会改变，并且变得和代码片段中定义的一样。

Answer 1

我觉得你遇到的问题是因为日志记录的层级传播有点复杂。简单来说，任何在“elasticsearch.trace”中记录的信息，只要它的日志级别符合这个记录器的要求，就会先传递到“elasticsearch”记录器，然后再传递到根记录器（也就是“”）。需要注意的是，一旦信息通过了“elasticsearch.trace”记录器的日志级别检查，父级记录器（“elasticsearch”和根记录器）的日志级别就不再检查了，但所有信息都会发送给处理器（handlers）。处理器本身的日志级别是会被考虑的。

下面是一个例子，能帮助你理解这个问题，以及一个可能的解决方案：

import logging

# The following line will basicConfig() the root handler
logging.info('DUMMY - NOT SEEN')
ll = logging.getLogger('foo')
ll.setLevel('DEBUG')
ll.addHandler(logging.StreamHandler())
ll.debug('msg1')
ll.propagate = False
ll.debug('msg2')

输出结果：

msg1
DEBUG:foo:msg1
msg2

你会看到“msg1”被“foo”记录器和它的父级根记录器同时记录（显示为“DEBUG:foo:msg1”）。然后，当在“msg2”之前关闭传播 ll.propagate = False 时，根记录器就不再记录它了。如果你把第一行（logging.info("DUMMY...")）注释掉，那么行为就会改变，根记录器的那一行就不会显示了。这是因为 logging 模块的顶层函数 info()、debug() 等在还没有定义处理器时，会自动为根记录器配置一个处理器。这也是为什么当你通过 logger = logging.getLogger() 修改根处理器时，你会看到不同的行为。

我在你的代码中没有看到你对根记录器做了什么，但正如你所见，代码或库中的一个随意的 logging.info() 之类的调用会导致添加一个处理器。

所以，针对你的问题，我建议你把 logger.propagate = False 设置在那些你觉得合适并且希望传播的记录器上，同时检查处理器本身的日志级别是否符合你的要求。

这里有一个尝试：

es_logger = logging.getLogger('elasticsearch')
es_logger.propagate = False
es_logger.setLevel(logging.INFO)
es_logger_handler=logging.handlers.RotatingFileHandler('top-camps-base.log',
                                                      maxBytes=0.5*10**9,
                                                      backupCount=3)
es_logger.addHandler(es_logger_handler)

es_tracer = logging.getLogger('elasticsearch.trace')
es_tracer.propagate = False
es_tracer.setLevel(logging.DEBUG)
es_tracer_handler=logging.handlers.RotatingFileHandler('top-camps-full.log',
                                                   maxBytes=0.5*10**9,
                                                   backupCount=3)
es_tracer.addHandler(es_tracer_handler)

logger = logging.getLogger('mainLog')
logger.propagate = False
logger.setLevel(logging.DEBUG)
# create file handler
fileHandler = logging.handlers.RotatingFileHandler('top-camps.log',
                                               maxBytes=10**6,
                                               backupCount=3)
fileHandler.setLevel(logging.INFO)
# create console handler
consoleHandler = logging.StreamHandler()
consoleHandler.setLevel(logging.INFO)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
consoleHandler.setFormatter(formatter)
fileHandler.setFormatter(formatter)
# add the handlers to logger
logger.addHandler(consoleHandler)
logger.addHandler(fileHandler)