CODEWITHSUNDEEP
pythonlogging
Anti-Distinctlyminty
Anti-Distinctlyminty

Reputation: 2775

Python Logging Module Inconsistent Behaviour

I've seen some very odd behaviour with the logger module. It started with a relatively complex project, but now I've seen it with the following script:

import logging
import os

# Uncomment the following line to remove handlers
# logging.getLogger().handlers = [] 

filePath = os.environ['userprofile']  + r'\Documents\log.txt'
logging.basicConfig(filename=filePath)
logging.debug('Gleep')
logging.shutdown()

This should simply write 'Gleep' to the log.txt file to your documents. Currently it is writing the file but not writing anything to it, however, I've inconsistently seen the following behaviour:

  1. List item
  2. No log file being written at all.
  3. Log file created, but nothing written to it.
  4. Everything working fine.

The only way I've got it working before is to remove existing handlers (commented out in the example above). This is on several machines in different locations.

So...am I doing something grotesquely wrong here? Why is the logging module acting this way?

Upvotes: 0

Views: 366

Answers (1)

Brad Solomon
Brad Solomon

Reputation: 40878

I'm not sure how to prove/disprove/debug your 'other' situations, but maybe the following can help clarify what is happening in the code from your question:

First, setting logging.getLogger().handlers = [] should not be necessary, since logging.getLogger() is the root logger by default and has no handlers. Here is a fresh Python 3.7 shell:

>>> import logging
>>> logging.getLogger()
<RootLogger root (WARNING)>
>>> logging.getLogger().handlers
[]

(Note that in the absence of any handlers, a logger will fall back to lastResort, but that should be irrelevant here since you add a handler implicitly via basicConfig().)

Which brings you to logging.basicConfig(filename=filePath): this adds a FileHandler handler to the root logger. It does not touch the level of the root logger, which is WARNING by default, so your message won't pass the 'level test' and won't be emitted as a result.

>>> logging.root.getEffectiveLevel()
30

(This uses .getEffectiveLevel() rather than just the plain attribute because a logger will walk its hierarchy until it finds a level if its level is NOTSET.)

All that is to say: as you currently have it, you are logging from the root logger (level WARNING) a message object that has level DEBUG, so the message will go nowhere.

Upvotes: 2

Related Questions