Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > comp.lang.python > #86842 > unrolled thread

Logging custom level not print module properly??

Started byDidymus <lynto28@gmail.com>
First post2015-03-03 06:06 -0800
Last post2015-03-03 08:30 -0700
Articles 4 — 3 participants

Back to article view | Back to comp.lang.python

Contents

  Logging custom level not print module properly?? Didymus <lynto28@gmail.com> - 2015-03-03 06:06 -0800
    Re: Logging custom level not print module properly?? Peter Otten <__peter__@web.de> - 2015-03-03 16:01 +0100
      Re: Logging custom level not print module properly?? Didymus <lynto28@gmail.com> - 2015-03-03 07:11 -0800
        Re: Logging custom level not print module properly?? Ian Kelly <ian.g.kelly@gmail.com> - 2015-03-03 08:30 -0700

#86842 — Logging custom level not print module properly??

FromDidymus <lynto28@gmail.com>
Date2015-03-03 06:06 -0800
SubjectLogging custom level not print module properly??
Message-ID<6676f6f6-94bf-4ed9-9a09-46beb4317e6c@googlegroups.com>
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.

   -Tom

[toc] | [next] | [standalone]

#86848

FromPeter Otten <__peter__@web.de>
Date2015-03-03 16:01 +0100
Message-ID<mailman.20.1425394911.21433.python-list@python.org>
In reply to#86842
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.

[toc] | [prev] | [next] | [standalone]

#86849

FromDidymus <lynto28@gmail.com>
Date2015-03-03 07:11 -0800
Message-ID<aada4054-154b-49bb-89e3-7650421b1a40@googlegroups.com>
In reply to#86848
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

[toc] | [prev] | [next] | [standalone]

#86850

FromIan Kelly <ian.g.kelly@gmail.com>
Date2015-03-03 08:30 -0700
Message-ID<mailman.21.1425396648.21433.python-list@python.org>
In reply to#86849

[Multipart message — attachments visible in raw view] — view raw

On Mar 3, 2015 8:16 AM, "Didymus" <lynto28@gmail.com> wrote:
> 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.

I believe the common approach is to let each module define and use its own
hierarchical logger named after the module, rather than have them all share
the root logger. This way the name that is logged is based on which logger
was used for logging and doesn't rely on the "module" attribute, which is
populated through the vagaries of stack inspection.

[toc] | [prev] | [standalone]

Back to top | Article view | comp.lang.python

csiph-web