Home     |     .Net Programming    |     cSharp Home    |     Sql Server Home    |     Javascript / Client Side Development     |     Ajax Programming

Ruby on Rails Development     |     Perl Programming     |     C Programming Language     |     C++ Programming     |     IT Jobs

Python Programming Language     |     Laptop Suggestions?    |     TCL Scripting     |     Fortran Programming     |     Scheme Programming Language


 
 
Cervo Technologies
The Right Source to Outsource

MS Dynamics CRM 3.0

Python Programming Language

Logging: how to suppress default output when adding handlers?


I am setting up handlers to log DEBUG and above to a rotating file and
ERROR and above to console.  But if any of my code calls a logger
(e.g., logging.error("foo")) before I setup my handlers, the logging
system will create a default logger that *also* emits logs, which I
can't seem to get rid of.  Is there a way I can suppress the creation
of this default logger, or remove it when I 'm setting up my handlers?
Thanks.

Sample code:

  import sys, logging, logging.handlers

  if len(sys.argv) > 1:
      logging.warning("Logging before setting handlers adds unwanted default logger")

  logging.getLogger().setLevel(logging.DEBUG)

  console = logging.StreamHandler()
  console.setLevel(logging.ERROR)
  console.setFormatter(logging.Formatter('%(levelname)-8s %(module)s: %(message)s'))
  logging.getLogger().addHandler(console)

  filelog = logging.handlers.RotatingFileHandler("/tmp/logtest2.log")
  filelog.setFormatter(logging.Formatter('%(asctime)s %(levelname)-8s %(module)s: %(message)s'))
  filelog.setLevel(logging.DEBUG)      # NOP since default above is DEBUG, but OK
  logging.getLogger().addHandler(filelog)

  logging.debug("TEST debug")
  logging.warning("TEST warning")
  logging.error("TEST error")

Sample runs, first without initial log call (good), then with one
showing the default log messages in the mix (bad); I'm showing the
console and tailing the logfile so they're mixed together but the
timestamp indicates the file logs:

  chris@Bacalao:/tmp<103> tail -f /tmp/logtest2.log &

  chris@Bacalao:/tmp<118> python /tmp/logtest2.py
  2007-06-05 09:36:27,234 DEBUG    logtest2: TEST debug
  2007-06-05 09:36:27,234 WARNING  logtest2: TEST warning
  ERROR    logtest2: TEST error
  2007-06-05 09:36:27,239 ERROR    logtest2: TEST error

  chris@Bacalao:/tmp<119> python /tmp/logtest2.py  this gives ugly logger
  WARNING:root:Logging before setting handlers adds unwanted default logger
  DEBUG:root:TEST debug
  2007-06-05 09:36:30,069 DEBUG    logtest2: TEST debug
  WARNING:root:TEST warning
  2007-06-05 09:36:30,072 WARNING  logtest2: TEST warning
  ERROR:root:TEST error
  ERROR    logtest2: TEST error
  2007-06-05 09:36:30,073 ERROR    logtest2: TEST error

On Jun 5, 2:44 pm, Chris Shenton <c@shenton.org> wrote:

> I am setting up handlers to log DEBUG and above to a rotating file and
> ERROR and above to console.  But if any of my code calls a logger
> (e.g.,logging.error("foo")) before I setup my handlers, thelogging
> system will create a default logger that *also* emits logs, which I
> can't seem to get rid of.  Is there a way I can suppress the creation
> of this default logger, or remove it when I 'm setting up my handlers?
> Thanks.

The default handler is created because you are calling the convenience
functions of the logging package: logging.error, etc. If you don't
want the default handler to be created, either

(a) Configure the logging system yourself before any logging call is
made (I'm not sure why you're not doing this - it could be done in
your main script before anything else happens) - or
(b) Make calls on a specific named logger, e.g.
logging.getLogger("logtest2").error("foo"), rather than
logging.error("foo") which is for casual/unsophisticated use only.

Regards,

Vinay Sajip

Vinay Sajip <vinay_sa@yahoo.co.uk> writes:
> The default handler is created because you are calling the convenience
> functions of the logging package: logging.error, etc. If you don't
> want the default handler to be created, either

> (a) Configure the logging system yourself before any logging call is
> made (I'm not sure why you're not doing this - it could be done in
> your main script before anything else happens) - or

Yeah, I think this is the cause.  Unfortunately I'm using a couple
dozen files and a bunch more libraries and if they're doing a
logging.debug() or whatnot they're creating this.  

Do you have any ideas how I can trace where the first call is made?
This seems a newbie question but if I have a bunch of other files
which do stuff like "from sqlalchemy import *" they might be invoking
a logging call so I'm not sure how to chase these down.

> (b) Make calls on a specific named logger, e.g.
> logging.getLogger("logtest2").error("foo"), rather than
> logging.error("foo") which is for casual/unsophisticated use only.

I'm dreading having to be so verbose with my (copious) loggers, which
is why I was curious if there was a way to nuke any auto-created
ones.  I thought calling logging.shutdown() before configuring my
loggers might do this but it didn't.  

Thanks.

On Jun 5, 8:38 pm, Chris Shenton <c@shenton.org> wrote:

> Yeah, I think this is the cause.  Unfortunately I'm using a couple
> dozen files and a bunch more libraries and if they're doing a logging.debug() or whatnot they're creating this.

I wouldn't have thought that well-written third party libraries (like
SQLAlchemy) would log to the root logger. It's by logging to an
application or library-specific logger that people can see where the
events are being generated - logging to the root logger means a lot of
useful information is lost.

> Do you have any ideas how I can trace where the first call is made?
> This seems a newbie question but if I have a bunch of other files
> which do stuff like "from sqlalchemy import *" they might be invoking
> a logging call so I'm not sure how to chase these down.

I presume you are starting the ball rolling using one or more scripts.
As long as you are not making logging calls at import time, then you
can configure logging in your main script, e.g.

if __name__ == "__main__":
  logging.basicConfigure(...)

> I'm dreading having to be so verbose with my (copious) loggers, which
> is why I was curious if there was a way to nuke any auto-created
> ones.  I thought callinglogging.shutdown() before configuring my
> loggers might do this but it didn't.

No need to be particularly verbose. One convention is for each module
to:

# for module foo/bar/baz.py

# Near the top of the module...
import logging

logger = logging.getLogger("foo.bar.baz")

# Then, in the rest of the module...

logger.debug("Test debug output") # No more verbose than
logging.debug("Test debug output")

Even if you have a dozen files, it should be easy to do search/replace
across them without too much trouble.

Regards,

Vinay Sajip

Add to del.icio.us | Digg this | Stumble it | Powered by Megasolutions Inc