how to use logging module to log an object like print()

[davy zhang]

mport logging
import pickle


# create logger
logger = logging.getLogger("simple_example")
logger.setLevel(logging.DEBUG)
# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
# create formatter
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s
- %(message)s ")
# add formatter to ch
ch.setFormatter(formatter)
# add ch to logger
logger.addHandler(ch)

d = {'key':'msg','key2':'msg2'}

# "application" code
logger.debug("debug message",d)#can not do this
logger.info("info message")
logger.warn("warn message")
logger.error("error message")
logger.critical("critical message")

 

[Diez B. Roggisch]

mport logging
import pickle


# create logger
logger = logging.getLogger("simple_example")
logger.setLevel(logging.DEBUG)
# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
# create formatter
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s
- %(message)s ")
# add formatter to ch
ch.setFormatter(formatter)
# add ch to logger
logger.addHandler(ch)

d = {'key':'msg','key2':'msg2'}

# "application" code
logger.debug("debug message",d)#can not do this

logger.debug("yes you can: %r", d)


Diez

 

[davy zhang]

thanks so much , I ganna check the formatter str for more info

 

[Steve Holden]

logger.debug("yes you can: %r", d)

One deficiency of this approach, however, is that the string formatting
is performed even when no logging is required, thereby wasting a certain
amount of effort on unnecessary formatting.

regards
Steve

 

[Vinay Sajip]

One deficiency of this approach, however, is that the string formatting
is performed even when nologgingis required, thereby wasting a certain
amount of effort on unnecessary formatting.

Though you can mitigate this using the pattern:

if logger.isEnabledFor(logging.DEBUG):
logger.debug("Message with variable data which may be expensive:
%s", expensive_call())

Which will only make the expensive_call() and formatting when the
logging call will actually do something.

Regards,

Vinay Sajip

 

[bieffe62]

One deficiency of this approach, however, is that the string formatting
is performed even when no logging is required, thereby wasting a certain
amount of effort on unnecessary formatting.

regards
 Steve

Sure about that?

This is the implementation of Logger.debug in
the file : ..Python25\lib\logging\__init__.py

def debug(self, msg, *args, **kwargs):
"""
Log 'msg % args' with severity 'DEBUG'.

To pass exception information, use the keyword argument
exc_info with
a true value, e.g.

logger.debug("Houston, we have a %s", "thorny problem",
exc_info=1)
"""
if self.manager.disable >= DEBUG:
return
if DEBUG >= self.getEffectiveLevel():
apply(self._log, (DEBUG, msg, args), kwargs)


The other methods (info, warning, ...) are similar. It looks like
the formatting is only done if actually used.

Ciao

 

[Diez B. Roggisch]

One deficiency of this approach, however, is that the string formatting
is performed even when no logging is required, thereby wasting a certain
amount of effort on unnecessary formatting.

Nope, it's not. It only happens when the message is really logged.

Diez

 

[Steve Holden]

Sure about that?

This is the implementation of Logger.debug in
the file : ..Python25\lib\logging\__init__.py

def debug(self, msg, *args, **kwargs):
"""
Log 'msg % args' with severity 'DEBUG'.

To pass exception information, use the keyword argument
exc_info with
a true value, e.g.

logger.debug("Houston, we have a %s", "thorny problem",
exc_info=1)
"""
if self.manager.disable >= DEBUG:
return
if DEBUG >= self.getEffectiveLevel():
apply(self._log, (DEBUG, msg, args), kwargs)


The other methods (info, warning, ...) are similar. It looks like
the formatting is only done if actually used.

Pretty sure, and Vinay's reply convinced me I was correct. He should
know, after all ...

regards
Steve

 

[Steve Holden]

Nope, it's not. It only happens when the message is really logged.

Vinay, please tell me whether I was right or wrong ...

regards
Steve

 

[Tim Roberts]

Vinay, please tell me whether I was right or wrong ...

If you will forgive me for putting words into your mouth, Steve, I suspect
that you originally read the line as this:
logger.debug("yes you can: %r" % d)
instead of what was actually written:
logger.debug("yes you can: %r" , d)

With the %, of course the formatting will be done whether or not the string
is logged. With the comma, the string formatting is done inside the logger
module, and will be skipped if the message is not needed.

This is exactly why logger supports this somewhat unusual feature. Now,
one can certainly imagine circumstances where the parameter evaluation is
expensive, so Vinay's bypass is still useful in some circumstances.

 

[Vinay Sajip]

Vinay, please tell me whether I was right or wrong ...

What Tim Roberts has already said is right ... my post was
highlighting how to mitigate any overhead which is typically (or at
least in general terms) higher than the cost of formatting, viz. the
computation of the values which get formatted.

Regards,

Vinay Sajip