473,320 Members | 1,612 Online
Bytes | Software Development & Data Engineering Community
Post Job

Home Posts Topics Members FAQ

Join Bytes to post your question to a community of 473,320 software developers and data experts.

Problem with logging module

I have a logger class that uses the Python logging module. When I
call it within a program using the unittest module, I get one line in
the log file for the first test, two identical ones for the second,
etc. I'm using local variables, which should go out of context with
each test. Setting the 'propagate' property to False doesn't have any
affect.

import logging, os, signal, sys
from datetime import datetime

class Logger:
def __init__(self, dir, name):
self.dir = dir
self.name = name

self.logger = logging.getLogger(name)
self.logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
self.logger.addHandler(handler)
self.logger.setLevel(logging.INFO)

def log(self, text):
msg = datetime.utcnow().isoformat(' ') + ' ' + sys.argv[0] + ' -- '
+ text
self.logger.info(msg)

import os, sys, unittest
import log

class Test(unittest.TestCase):

def test_1(self):
homedir = sys.path[0]
logger = log.Logger(homedir, "test")
logger.log("Test 1")

def test_2(self):
homedir = sys.path[0]
logger = log.Logger(homedir, "test")
logger.log("Test 2")

def test_3(self):
homedir = sys.path[0]
logger = log.Logger(homedir, "test")
logger.log("Test 3")

def test_4(self):
homedir = sys.path[0]
logger = log.Logger(homedir, "test")
logger.log("Test 4")

def test_5(self):
homedir = sys.path[0]
logger = log.Logger(homedir, "test")
logger.log("Test 5")

if __name__ == '__main__':
unittest.main()

And the output file looks like:

2004-10-13 15:54:08.321112 test.py -- Test 1
2004-10-13 15:54:08.326594 test.py -- Test 2
2004-10-13 15:54:08.326594 test.py -- Test 2
2004-10-13 15:54:08.329742 test.py -- Test 3
2004-10-13 15:54:08.329742 test.py -- Test 3
2004-10-13 15:54:08.329742 test.py -- Test 3
2004-10-13 15:54:08.333411 test.py -- Test 4
2004-10-13 15:54:08.333411 test.py -- Test 4
2004-10-13 15:54:08.333411 test.py -- Test 4
2004-10-13 15:54:08.333411 test.py -- Test 4
2004-10-13 15:54:08.336997 test.py -- Test 5
2004-10-13 15:54:08.336997 test.py -- Test 5
2004-10-13 15:54:08.336997 test.py -- Test 5
2004-10-13 15:54:08.336997 test.py -- Test 5
2004-10-13 15:54:08.336997 test.py -- Test 5
Jul 18 '05 #1
8 1966
> self.logger = logging.getLogger(name)
self.logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
self.logger.addHandler(handler)

^^^^
Thats your problem - only set the handler once for the runtime of your
program.

--
Regards,

Diez B. Roggisch
Jul 18 '05 #2
Steve Erickson wrote:
I have a logger class that uses the Python logging module. When I
call it within a program using the unittest module, I get one line in
the log file for the first test, two identical ones for the second,
etc. I'm using local variables, which should go out of context with
each test. Setting the 'propagate' property to False doesn't have any
affect.

import logging, os, signal, sys
from datetime import datetime

class Logger:
def __init__(self, dir, name):
self.dir = dir
self.name = name

self.logger = logging.getLogger(name)
self.logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
self.logger.addHandler(handler)
self.logger.setLevel(logging.INFO)

def log(self, text):
msg = datetime.utcnow().isoformat(' ') + ' ' + sys.argv[0] + ' -- '
+ text
self.logger.info(msg)


As I understand it, logging uses internal (global/"static") data
structures to keep track of all instantiated loggers. Thus, each time
you create an instance of your logger class, it gets the (pre-existing)
logging.Logger instance named "test" and adds a *new* FileHandler to
it. Thus, you end up with an ever-growing list of (identical) handlers
on the same logging.Logger instance.

You can fix this either by using a global log.Logger object, or by
having a separate initialize() method for it that's called only once and
which adds the handler and sets the logging level.

By the way, you can also set a formatter on the handler which will
automatically include the time (and probably sys.argv[0] as well). With
that done, you could do away with your class. Just initialize the
logger once, and then in each test case, you can do

logging.getLogger("test").info(text)

The logging module will keep track of all of the handler and formatting
details for you.

Jeff Shannon
Technician/Programmer
Credit International

Jul 18 '05 #3
"Diez B. Roggisch" <de*********@web.de> wrote in message news:<ck*************@news.t-online.com>...
self.logger = logging.getLogger(name)
self.logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
self.logger.addHandler(handler)

^^^^
Thats your problem - only set the handler once for the runtime of your
program.

Thanks. Coming from C++, I thought that the local logger instance in
each test method would go away when I went out of the context of the
method. Sounds like the logging class in Python maintains artifacts
that affect instantiations in other methods. Or maybe I'm confused
about how Python handles local versus class variables.
Jul 18 '05 #4
Steve Erickson wrote:
Thanks. Coming from C++, I thought that the local logger instance in
each test method would go away when I went out of the context of the
method. Sounds like the logging class in Python maintains artifacts
that affect instantiations in other methods. Or maybe I'm confused
about how Python handles local versus class variables.


Nothing to do with python - its the way logging is designed, and it makes
sense: if at one place you attach the logger named foo.bar to a handler,
and at another place obtain a reference to foo.bar to log some stuff, you
don't want to reiterate the whole handler-attaching stuff.

So you simply abused the logging module - just set up the logger once, and
then obtain a reference to it using logging.getLogger whenever you need it
- that totally rids you of your logger class, that so far doesn't do much
anyway. Like this:

------
logger = logging.getLogger(name)
logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
logger.addHandler(handler)

class Test:

def test_me(self):
logger = logging.getLogger(name)
logger.debug("test_me")

------
--
Regards,

Diez B. Roggisch
Jul 18 '05 #5
Thanks a bunch for your patience and explanations. It would be nice
if there was a method of checking the logger or handler for an
instance of it:

logger = logging.getLogger(name)
if not logger.handler(dir + '/' + name + '.log'):
logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
logger.addHandler(handler)

"Diez B. Roggisch" <de*********@web.de> wrote in message news:<ck*************@news.t-online.com>...
Steve Erickson wrote:
Thanks. Coming from C++, I thought that the local logger instance in
each test method would go away when I went out of the context of the
method. Sounds like the logging class in Python maintains artifacts
that affect instantiations in other methods. Or maybe I'm confused
about how Python handles local versus class variables.


Nothing to do with python - its the way logging is designed, and it makes
sense: if at one place you attach the logger named foo.bar to a handler,
and at another place obtain a reference to foo.bar to log some stuff, you
don't want to reiterate the whole handler-attaching stuff.

So you simply abused the logging module - just set up the logger once, and
then obtain a reference to it using logging.getLogger whenever you need it
- that totally rids you of your logger class, that so far doesn't do much
anyway. Like this:

------
logger = logging.getLogger(name)
logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
logger.addHandler(handler)

class Test:

def test_me(self):
logger = logging.getLogger(name)
logger.debug("test_me")

------

Jul 18 '05 #6
Steve Erickson wrote:
Thanks a bunch for your patience and explanations. It would be nice
if there was a method of checking the logger or handler for an
instance of it:

logger = logging.getLogger(name)
if not logger.handler(dir + '/' + name + '.log'):
logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
logger.addHandler(handler)


There is the (unfortunately undocumented) property "handlers" on a Logger
insnstance that you can use:

if not fname in [h.stream.name for h in logger.handlers]:
...

--
Regards,

Diez B. Roggisch
Jul 18 '05 #7
[Steve]
if not logger.handler(dir + '/' + name + '.log'):
[Diez] There is the (unfortunately undocumented) property "handlers" on a Logger
insnstance that you can use:


The handlers property is not documented because it is not normally
meant to be used by clients of the logging package. Since handlers can
include third party handlers, the answer to 'what is an existing
handler?' is not in general known to the logging package. This is why
something like the functionality suggested by Steve is not provided in
the box.

Regards,
Vinay Sajip
Jul 18 '05 #8
"Diez B. Roggisch" <de*********@web.de> wrote in message news:<ck*************@news.t-online.com>...
Steve Erickson wrote:
Thanks a bunch for your patience and explanations. It would be nice
if there was a method of checking the logger or handler for an
instance of it:

logger = logging.getLogger(name)
if not logger.handler(dir + '/' + name + '.log'):
logger.propagate = False
handler = logging.FileHandler(dir + '/' + name + '.log')
logger.addHandler(handler)


There is the (unfortunately undocumented) property "handlers" on a Logger
insnstance that you can use:

if not fname in [h.stream.name for h in logger.handlers]:
...


Excellent!! Thanks.
Jul 18 '05 #9

This thread has been closed and replies have been disabled. Please start a new discussion.

Similar topics

6
by: Ville Vainio | last post by:
Just posting this for the sake of google: Like everyone else, I figured it's time to start using the 'logging' module. I typically want to dump "info" level (and up) log information to...
2
by: rh0dium | last post by:
Hi all, So I have a slice of code which calls other python code. I have started to take a real liking to the logging module, but I want to extend this into the called python code. I have no...
1
by: Maksim Kasimov | last post by:
hello in my modules, I'm using logging module, doing thus (there is a few modules): in module1.py: hdl = logging.StreamHandler() fmt =...
23
by: Rotem | last post by:
Hi, while working on something in my current project I have made several improvements to the logging package in Python, two of them are worth mentioning: 1. addition of a logging record field...
0
by: robert | last post by:
As more and more python packages are starting to use the bloomy (Java-ish) 'logging' module in a mood of responsibility and as I am not overly happy with the current "thickener" style of usage, I...
5
by: Ritesh Raj Sarraf | last post by:
import os, sys, logging logger = logging.getLogger("my_app") conerr = logging.StreamHandler(sys.stderr) conerr.setLevel(logging.DEBUG) conerr_formatter = logging.Formatter('%(levelname)s...
12
by: Tekkaman | last post by:
I'm getting a strange behaviour from the "pathname" and "lineno" formatter mapping keys. Instead of my file and my line number I get: /usr/lib/python2.4/logging/__init__.py as the file, and...
0
by: Karlo Lozovina | last post by:
I've just upgraded to Python 2.5, SQLAlchemy 0.3.3, and py2exe 0.6.5 (the py2.5 version, yes). Simple: --- import sqlalchemy print 'Test' ---
3
by: Lowell Alleman | last post by:
Here is the situation: I wrote my own log handler class (derived from logging.Handler) and I want to be able to use it from a logging config file, that is, a config file loaded with the...
0
by: DolphinDB | last post by:
Tired of spending countless mintues downsampling your data? Look no further! In this article, you’ll learn how to efficiently downsample 6.48 billion high-frequency records to 61 million...
1
isladogs
by: isladogs | last post by:
The next Access Europe meeting will be on Wednesday 6 Mar 2024 starting at 18:00 UK time (6PM UTC) and finishing at about 19:15 (7.15PM). In this month's session, we are pleased to welcome back...
0
by: Vimpel783 | last post by:
Hello! Guys, I found this code on the Internet, but I need to modify it a little. It works well, the problem is this: Data is sent from only one cell, in this case B5, but it is necessary that data...
0
by: jfyes | last post by:
As a hardware engineer, after seeing that CEIWEI recently released a new tool for Modbus RTU Over TCP/UDP filtering and monitoring, I actively went to its official website to take a look. It turned...
0
by: ArrayDB | last post by:
The error message I've encountered is; ERROR:root:Error generating model response: exception: access violation writing 0x0000000000005140, which seems to be indicative of an access violation...
1
by: PapaRatzi | last post by:
Hello, I am teaching myself MS Access forms design and Visual Basic. I've created a table to capture a list of Top 30 singles and forms to capture new entries. The final step is a form (unbound)...
1
by: CloudSolutions | last post by:
Introduction: For many beginners and individual users, requiring a credit card and email registration may pose a barrier when starting to use cloud servers. However, some cloud server providers now...
1
by: Defcon1945 | last post by:
I'm trying to learn Python using Pycharm but import shutil doesn't work
0
by: af34tf | last post by:
Hi Guys, I have a domain whose name is BytesLimited.com, and I want to sell it. Does anyone know about platforms that allow me to list my domain in auction for free. Thank you

By using Bytes.com and it's services, you agree to our Privacy Policy and Terms of Use.

To disable or enable advertisements and analytics tracking please visit the manage ads & tracking page.