Path: csiph.com!usenet.pasdenom.info!weretis.net!feeder1.news.weretis.net!feeder.erje.net!eu.feeder.erje.net!newsfeed.xs4all.nl!newsfeed4a.news.xs4all.nl!xs4all!newsgate.cistron.nl!newsgate.news.xs4all.nl!post.news.xs4all.nl!not-for-mail
To: python-list@python.org
From: Peter Otten <__peter__@web.de>
Subject: Re: Logging custom level not print module properly??
Date: Tue, 03 Mar 2015 16:01:28 +0100
Organization: None
References: <6676f6f6-94bf-4ed9-9a09-46beb4317e6c@googlegroups.com>
Mime-Version: 1.0
Content-Type: text/plain; charset="ISO-8859-1"
Content-Transfer-Encoding: 7Bit
User-Agent: KNode/4.13.3
Precedence: list
Newsgroups: comp.lang.python
Message-ID: <mailman.20.1425394911.21433.python-list@python.org>
Lines: 122
NNTP-Posting-Host: 2001:888:2000:d::a6
Xref: csiph.com comp.lang.python:86848

Didymus wrote:

> Hi,
> 
> I have setup custom levels (with the help of the Python community) for
> logging. I set this up as a class in a module "log.py" below. The problem
> I'm seeing is that no matter the file the the logging is happening in it
> always prints the module as "log", I've rcreated the testcase below:
> 
> % python run.py
> [PWARNING log 22] Warning Message.
> [INFO run 8] Message.
> 
> The log.py:
> 
> """ Logging Module """
> import common
> import logging
> 
> # Custom
> PWARNING_NUM = 34
> 
> # Performance Warning...
> logging.addLevelName(PWARNING_NUM, "PWARNING")
> 
> def pwarning(self, message, *args, **kws):
>     """ Performance Warning Message Level """
>     # Yes, logger takes its '*args' as 'args'.
>     self.log(PWARNING_NUM, message, *args, **kws)
>         
> logging.Logger.pwarning = pwarning
> 
> class SetLogging():
> # Variables.
>     fileHandler = None
>     consoleHandler = None
>     
>     def __init__(self):
>         """ Set Verbosity Level, set which ever is True..."""
>         common.verbosity = 'INFO'
>         self.setLogHandlers()
>   
>     def setverbosity(self, verbosity_level):
>         """ Set what the logging level should be """
>         level = logging.getLevelName(verbosity_level)
>         common.rootLogger.setLevel(level)
>     
>     def setLogHandlers(self):
>         """ Set logging file and level. """
>         logFormatter =  logging.Formatter("[%(levelname)s %(module)s
>         %(lineno)d] %(message)s") common.rootLogger = logging.getLogger()
> # Add a File to log too...
>         fileHandler = logging.FileHandler(common.LOG_FILENAME)
>         fileHandler.setFormatter(logFormatter)
>         common.rootLogger.addHandler(fileHandler)
> # Put the message on the Console as well..
>         consoleHandler = logging.StreamHandler()
>         consoleHandler.setFormatter(logFormatter)
>         common.rootLogger.addHandler(consoleHandler)
>         self.setverbosity(common.verbosity)
> 
> # Main
> if __name__ == '__main__':
>     log = SetLogging()
>     log.setLogHandlers()
>     log.setverbosity('PMESSAGE')
> 
> 
> run.py:
> import common
> import log
> #
> common.LOG_FILENAME = '/tmp/runtest.log'         # Set the File the log
> will write too based on the name and time stamp.
> log = log.SetLogging()                                                    
>         # Set logging level and handlers.
> 
> common.rootLogger.pwarning('Warning Message.')
> common.rootLogger.info('Message.')
> 
> 
> common.py:
> # Logging Verbosity and File.
> #
> rootLogger = None                                                         
>     # Logger Handle, Undefined at the moment.
> LOG_FILENAME = '/tmp/python.log'                                          
>     # Log File full pathname.
> 
> 
> Not sure why the "def pwarning" isnt; picking up the module that the call
> is happening in correctly, but the standard INFO is. Thanks for any help
> in advanced.

The findCaller() method determines that your pwarning() is not part of the 
logging machinery and thus presents the file containing the pwarning() 
function as the origin of the logging event. 

I see no easy and clean way to inform findCaller() to go up one more level 
(the unittest package checks for a global flag for that purpose), but that 
may be because I didn't look hard enough.

If your usecase for custom levels is compelling I suggest that you 
override/replace findCaller() rather than go for the following hack...

exec compile('''
# Custom
PWARNING_NUM = 34

# Performance Warning...
addLevelName(PWARNING_NUM, "PWARNING")

def pwarning(self, message, *args, **kws):
    """ Performance Warning Message Level """
    # Yes, logger takes its '*args' as 'args'.
    self.log(PWARNING_NUM, message, *args, **kws)

Logger.pwarning = pwarning
''', logging.__file__.rstrip("co"), "exec") in vars(logging)

...which pretends that pwarning() is part of the logging/__init__.py module.