在这个python代码samp中日志记录是如何发生的

Question

我试图通过摆弄this basic example来理解python日志记录。我在代码中添加了一些行并在下面复制。查找#added by me注释以查找我添加的行：

垃圾邮件_应用程序.py

import logging
import auxiliary_module

# create logger with 'spam_application'
logger = logging.getLogger('spam_application')
logger.setLevel(logging.DEBUG)
# create file handler which logs even debug messages
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
ch.setFormatter(formatter)
# add the handlers to the logger
logger.addHandler(fh)
logger.addHandler(ch)

logger.error("Testing logger err")   #added by me
logger.debug("desting logger debug") #added by me

logger.info('creating an instance of auxiliary_module.Auxiliary')
a = auxiliary_module.Auxiliary()
logger.info('created an instance of auxiliary_module.Auxiliary')
logger.info('calling auxiliary_module.Auxiliary.do_something')
a.do_something()
logger.info('finished auxiliary_module.Auxiliary.do_something')
logger.info('calling auxiliary_module.some_function()')
auxiliary_module.some_function()
logger.info('done with auxiliary_module.some_function()')

辅助_模块.py

import logging

# create logger
module_logger = logging.getLogger('spam_application.auxiliary')

class Auxiliary:
    def __init__(self):
        self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')
        self.logger.info('creating an instance of Auxiliary')

    def do_something(self):
        self.logger.info('doing something')
        a = 1 + 1
        self.logger.debug("a =%s", a)   #added by me
        self.logger.info('done doing something')
        self.logger.error("Testing logger err")     #added by me
        self.logger.debug("testing logger debug")   #added by me
        logging.debug("-->testing logger debug")    #added by me
        logging.error("-->testing logger err")      #added by me

def some_function():
    module_logger.info('received a call to "some_function"')

控制台输出

2018-09-07 18:43:57,041 - spam_application - ERROR - Testing logger err
2018-09-07 18:43:57,041 - spam_application.auxiliary.Auxiliary - ERROR - Testing logger err
ERROR:root:-->testing logger err
INFO:spam_application:finished auxiliary_module.Auxiliary.do_something
INFO:spam_application:calling auxiliary_module.some_function()
INFO:spam_application.auxiliary:received a call to "some_function"
INFO:spam_application:done with auxiliary_module.some_function()

垃圾邮件.log

2018-09-07 18:43:57,041 - spam_application - ERROR - Testing logger err
2018-09-07 18:43:57,041 - spam_application - DEBUG - desting logger debug
2018-09-07 18:43:57,041 - spam_application - INFO - creating an instance of auxiliary_module.Auxiliary
2018-09-07 18:43:57,041 - spam_application.auxiliary.Auxiliary - INFO - creating an instance of Auxiliary
2018-09-07 18:43:57,041 - spam_application - INFO - created an instance of auxiliary_module.Auxiliary
2018-09-07 18:43:57,041 - spam_application - INFO - calling auxiliary_module.Auxiliary.do_something
2018-09-07 18:43:57,041 - spam_application.auxiliary.Auxiliary - INFO - doing something
2018-09-07 18:43:57,041 - spam_application.auxiliary.Auxiliary - DEBUG - a =2
2018-09-07 18:43:57,041 - spam_application.auxiliary.Auxiliary - INFO - done doing something
2018-09-07 18:43:57,041 - spam_application.auxiliary.Auxiliary - ERROR - Testing logger err
2018-09-07 18:43:57,041 - spam_application.auxiliary.Auxiliary - DEBUG - testing logger debug
2018-09-07 18:43:57,042 - spam_application - INFO - finished auxiliary_module.Auxiliary.do_something
2018-09-07 18:43:57,042 - spam_application - INFO - calling auxiliary_module.some_function()
2018-09-07 18:43:57,042 - spam_application.auxiliary - INFO - received a call to "some_function"
2018-09-07 18:43:57,042 - spam_application - INFO - done with auxiliary_module.some_function()

怀疑

1. 为什么我会在控制台中看到下面的行？地址：

   INFO:spam_application:finished auxiliary_module.Auxiliary.do_something
   INFO:spam_application:calling auxiliary_module.some_function()
   INFO:spam_application.auxiliary:received a call to "some_function"
   INFO:spam_application:done with auxiliary_module.some_function()
   

2. 为什么控制台中的最后五行不遵循其他行的格式？

3. 为什么没有

   DEBUG:root:-->testing logger debug
   

4. 为什么这些行不在文件中：

   DEBUG:root:-->testing logger debug
   ERROR:root:-->testing logger err
   

5. 当我在子模块内调用logging.xyz()而不是logging.getLogger('abc').xyz()（这里是auxiliary_module）时，子模块日志记录的基本行为是什么？

Answer 1

1，2，3，4。 问题的本质是使用两个记录器。您用代码logger = logging.getLogger('spam_application')创建的第一个。第二个是根记录器。您是从代码logging.debug(" >testing logger debug")开始的。通常需要多个记录器来区分日志消息的来源。跟踪你的伐木工人，不要把他们混在一起。你知道吗

要轻松开始登录python，您可以只使用根记录器。您可以用logging.basicConfig(...)配置它，并用logging.info(...)创建日志消息。你知道吗

五。 它表现得很好。您不需要任何额外的操作就可以使日志正常工作。尽管在跨多个线程和进程进行日志记录时可能会遇到困难。你知道吗