Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Python Logging - AttributeError: module 'logging' has no attribute 'handlers'

Observation: When I comment out from logging import handlers the below-mentioned error is observed.

Error:
    file_handler =  logging.handlers.RotatingFileHandler(
AttributeError: module 'logging' has no attribute 'handlers'

Question: If i have imported the logging why is required to do from logging import handlers?

import logging
import sys
#from logging import handlers

def LoggerDefination():
    #file_handler = logging.FileHandler(filename='..\\logs\\BasicLogger_v0.1.log', mode='a')
    file_handler =  logging.handlers.RotatingFileHandler(
        filename="..\\logs\\BasicLogger_v0.2.log",
        mode='a',
        maxBytes=20000,
        backupCount=7,
        encoding=None,
        delay=0
    )
    file_handler.setLevel(logging.DEBUG)

    stdout_handler = logging.StreamHandler(sys.stdout)
    stdout_handler.setLevel(logging.DEBUG)
    handlers = [file_handler, stdout_handler]

    logging.basicConfig(
        level=logging.DEBUG,
        format='%(asctime)s | %(module)s | %(name)s | LineNo_%(lineno)d | %(levelname)s |  %(message)s',
        handlers=handlers
    )

def fnt_test_log1():
    LoggerDefination()
    WriteLog1 = logging.getLogger('fnt_test_log1')
    #WriteLog1.propagate=False
    WriteLog1.info("######## START OF : test_log1 ##########")
    WriteLog1.debug("test_log1 | This is debug level")
    WriteLog1.debug("test_log1 | This is debug level")
    WriteLog1.info("test_log1 | This is info level")
    WriteLog1.warning("test_log1 | This is warning level")
    WriteLog1.error("test_log1 | This is error level")
    WriteLog1.critical("test_log1 |This is critiacl level")
    WriteLog1.info("######## END OF : test_log1 ##########")


def fnt_test_log2():
    LoggerDefination()
    WriteLog2 = logging.getLogger('fnt_test_log2')
    WriteLog2.info("######## START OF : test_log2 ##########")
    WriteLog2.debug("test_log2 ===> debug")
    WriteLog2.debug("test_log2 | This is debug level")
    WriteLog2.debug("test_log2 | This is debug level")
    WriteLog2.info("test_log2 | This is info level")
    WriteLog2.warning("test_log2 | This is warning level")
    WriteLog2.error("test_log2 | This is error level")
    WriteLog2.critical("test_log2 |This is critiacl level")
    WriteLog2.info("######## STOP OF : test_log2 ##########")


if __name__ == '__main__':
    LoggerDefination()
    MainLog = logging.getLogger('main')
    LoggerDefination()
    MainLog.info("Executing script: " + __file__)
    fnt_test_log1()
    fnt_test_log2()
like image 808
amit chopra Avatar asked Nov 22 '20 08:11

amit chopra


2 Answers

This is a two-part answer: The first part concerns your immediate question. The second part concerns the question why your question might have come up in the first place (and, well, how I ended up in this thread, given that your question is already two months old).

First part (the answer to your question): When importing a package like import logging, Python by default never imports subpackages (or submodules) like logging.handlers but only exposes variables to you that are defined in the package's __init__.py file (in this case logging/__init__.py). Unfortunately, it's hard to tell from the outside if logging.handlers is a variable in logging/__init__.py or an actual separate module logging/handlers.py. So you have to take a look at logging/__init__.py and then you will see that it doesn't define a handlers variable and that, instead, there's a module logging/handlers.py which you need to import separately through import logging.handlers or from logging.handlers import TheHandlerYouWantToUse. So this should answer your question.

Second part: I recently noticed that my IDE (PyCharm) always suggests import logging whenever I actually want to use logging.handlers.QueueHandler. And for some arcane reason (and despite what I said in the first part) it's been working! …well, most of the time.

Specifically, in the following code, the type annotation causes the expected AttributeError: module 'logging' has no attribute 'handlers'. However, after commenting out the annotation (which for Python < 3.9 gets executed during module execution time), calling the function works – provided I call it "late enough" (more on that below).

import logging
from multiprocessing.queues import Queue


def redirect_logs_to_queue(
    logging_queue: Queue, level: int = logging.DEBUG
) -> logging.handlers.QueueHandler:  # <-------------------------------- This fails

    queue_handler = logging.handlers.QueueHandler(logging_queue)  # <--- This works
    root = logging.getLogger()
    root.addHandler(queue_handler)
    root.setLevel(level)
    return queue_handler

So what does "late enough" mean? Unfortunately, my application was a bit too complex to do some quick bug hunting. Nevertheless, it was clear to me that logging.handlers must "become available" at some point between start-up (i.e. all my modules getting loaded/executed) and invoking that function. This gave me the decisive hint: Turns out, some another module deep down the package hierarchy was doing from logging.handlers import RotatingFileHandler, QueueListener. This statement loaded the entire logging.handlers module and caused Python to "mount" the handlers module in its parent package logging, meaning that the logging variable would henceforth always come equipped with a handlers attribute even after a mere import logging, which is why I didn't need to import logging.handlers anymore (and which is probably what PyCharm noticed).

Try it out yourself:

This works:

import logging
from logging.handlers import QueueHandler
print(logging.handlers)

This doesn't:

import logging
print(logging.handlers)

All in all, this phenomenon is a result of Python's import mechanism using global state to avoid reloading modules. (Here, the "global state" I'm referring to is the logging variable that you get when you import logging.) While it is treacherous sometimes (as in the case above), it does make perfect sense: If you import logging.handlers in multiple modules, you don't want the code in the logging.handlers module to get loaded (and thus executed!) more than once. And so Python just adds the handlers attribute to the logging module object as soon as you import logging.handlers somewhere and since all modules that import logging share the same logging object, logging.handlers will suddenly be available everywhere.

like image 161
balu Avatar answered Oct 05 '22 00:10

balu


Perhaps you have some other module called logging which masks the standard library one. Is there some file called logging.py somewhere in your code base?

like image 45
Vinay Sajip Avatar answered Oct 05 '22 01:10

Vinay Sajip