RE: Unusual Exception Behaviour

[Robert Rawlins]

Hi Mk,

To tell the truth I have never used logging module extensively, so I'm
not expert in this area and can't help you there.

However, it seems to me that you may have stumbled upon some subtle bug
/ side effect of logging module that could cause some side effects in
exceptions. Or perhaps it surfaces only in combination with glib?

If you discover the root cause, please let us know on this ng, I'm also
using Python extensions and bindings to other libraries and this could
be of interest at least to me.

Yeah it's got me a little bemused to be honest, I've tried playing around
with configuration options this morning and not been able to achieve
anything that works properly.

I'll keep testing though and as soon as I have a root cause to the problem
I'll be sure to let the list know.

Thanks mate,

Robert

[Vinay Sajip]

On Jul 18, 12:03 pm, "Robert Rawlins"
<[e-mail]:

>
Yeah it's got me a little bemused to be honest, I've tried playing around
with configuration options this morning and not been able to achieve
anything that works properly.

The logging configuration functionality provided by fileConfig is all-
or-nothing, i.e. it does not support incremental configuration.

Do you know if any libraries you depend on use fileConfig?

If you use programmatic configuration only, and don't use fileConfig
at all, does everything work as expected?

Regards,

Vinay Sajip

[Robert Rawlins]

The logging configuration functionality provided by fileConfig is all-

or-nothing, i.e. it does not support incremental configuration.

Do you know if any libraries you depend on use fileConfig?

If you use programmatic configuration only, and don't use fileConfig
at all, does everything work as expected?

Vinay,

I changed this over to programmatic configuration this afternoon and it
works just great, all the logging I require, and my exceptions get thrown.
:-D

I have no idea if any of the librarys I use work from a file config, I'm
certainly not aware of them doing so.

This is really quite frustrating as I'd much rather use a conf file than
work this programmatically. I get the feeling that it's because in the
config file I was not attaching any handlers to the root logger, but I don't
know.

Robert

[Vinay Sajip]

On Jul 18, 5:12 pm, "Robert Rawlins"
<[e-mail]:

>
This is really quite frustrating as I'd much rather use a conf file than
work this programmatically. I get the feeling that it's because in the
config file I was not attaching any handlers to the root logger, but I don't
know.

There's no reason why not having a handler for the root logger would
cause any particular problem. For example, the following script:

#- start of logconftest.py ------------------
import logging, logging.config

logging.config.fileConfig("log.conf")

app_logger = logging.getLogger("application")
sa_logger = logging.getLogger("sqlalchemy")

loggers = [app_logger, sa_logger]

def func1():
raise Exception("Exception from func1")

def func2():
raise TypeError("TypeError from func2")

def func3():
raise ValueError("ValueError from func3")

funcs = [func1, func2, func3]

for x in range(10):
try:
f = funcs[x % 3]
f()
except Exception, e:
loggers[x % 2].exception("%d. Problem in %s", x, f.__name__)
#- end of logconftest.py --------------------

together with the following configuration file (almost the same as
yours):

;-- start of log.conf -----------------------
[loggers]
keys=root,application,sqlalchemy

[handlers]
keys=hand01,hand03

[formatters]
keys=form01

[logger_root]
level=DEBUG
handlers=

[logger_application]
level=DEBUG
handlers=hand01
qualname=application

[logger_sqlalchemy]
level=DEBUG
handlers=hand03
qualname=sqlalchemy

[handler_hand01]
class=handlers.RotatingFileHandler
level=DEBUG
formatter=form01
args=('application.log', 'a', 800000, 5)

[handler_hand03]
class=handlers.RotatingFileHandler
level=DEBUG
formatter=form01
args=('sqlalchemy.log', 'a', 800000, 5)

[formatter_form01]
format=%(asctime)s %(filename)s %(lineno)d %(levelname)-8s %(message)s
datefmt=
class=logging.Formatter
;-- end of log.conf -------------------------

gives the following output:

-- start of application.log -----------------
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 0. Problem in func1
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 11, in func1
raise Exception("Exception from func1")
Exception: Exception from func1
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 2. Problem in func3
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 17, in func3
raise ValueError("ValueError from func3")
ValueError: ValueError from func3
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 4. Problem in func2
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 14, in func2
raise TypeError("TypeError from func2")
TypeError: TypeError from func2
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 6. Problem in func1
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 11, in func1
raise Exception("Exception from func1")
Exception: Exception from func1
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 8. Problem in func3
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 17, in func3
raise ValueError("ValueError from func3")
ValueError: ValueError from func3
-- end of application.log -------------------

-- start of sqlalchemy.log ------------------
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 1. Problem in func2
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 14, in func2
raise TypeError("TypeError from func2")
TypeError: TypeError from func2
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 3. Problem in func1
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 11, in func1
raise Exception("Exception from func1")
Exception: Exception from func1
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 5. Problem in func3
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 17, in func3
raise ValueError("ValueError from func3")
ValueError: ValueError from func3
2008-07-20 14:47:05,608 logconftest.py 26 ERROR 7. Problem in func2
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 14, in func2
raise TypeError("TypeError from func2")
TypeError: TypeError from func2
2008-07-20 14:47:05,625 logconftest.py 26 ERROR 9. Problem in func1
Traceback (most recent call last):
File "C:\Temp\logconftest.py", line 24, in <module>
f()
File "C:\Temp\logconftest.py", line 11, in func1
raise Exception("Exception from func1")
Exception: Exception from func1
-- end of sqlalchemy.log --------------------
which is, from a quick scan, the expected result - all the expected
exceptions are thrown. Note the absence of any handlers on the root
logger.

Regards,

Vinay Sajip