Logging custom level not print module properly??

[Didymus]

On Tuesday, March 3, 2015 at 10:02:02 AM UTC-5, Peter Otten wrote:
> 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.

Thanks! I'll take a look.

I did find that if I changed the "self.log" to "self._log" it works correctly but gives me a pylint warning about acccess to a protected member _log..

def pwarning(self, message, *args, **kws):
    """ Performance Warning Message Level """
    # Yes, logger takes its '*args' as 'args'.
    self._log(PWARNING_NUM, message, args, **kws)

Still wondering what the correct Pythonic way to handle this.

  -Tom