python logging writes an empty file

[Ovidiu Deac]

Hi,

I have the following situation:

My application uses nosetests to discover&run the unittests. I pass
the log configuration file as --logging-config=logging.conf
Everything works just fine, the logs are printed as required by the
configuration file which makes me happy. I take this as a sign that my
logging.conf is correct

Then in my main script, which starts the production application, I
have this line:
logging.config.fileConfig("logging.conf")

The logging module is configured without errors BUT my output.log is
EMPTY. It's like all the messages are filtered.

If I configure logging like this:
logging.basicConfig(level=logging.INFO,
format='%(asctime)s %(name)-12s %(levelname)s: %(message)s',
datefmt='%m-%d %H:%M:%S',
filename=file,
filemode='w')
Then the logs are printed ok.

Then I tried this:
file = logging.FileHandler(logFileBasename, 'w')
file.setLevel(logging.INFO)
# set a format which is simpler for console use
formatter = logging.Formatter('%(asctime)s %(name)-12s
%(levelname)-8s %(message)s',)
# tell the handler to use this format
file.setFormatter(formatter)
# add the handler to the root logger
logging.getLogger('').addHandler(file)
logging.getLogger('')

...which also leaves my output file EMPTY.

I'm out of ideas. Can anybody help me with this?

Thanks in advance!
ovidiu

Here is my logging.conf:

[formatters]
keys: detailed,simple

[handlers]
keys: console,file

[loggers]
keys: root

[formatter_simple]
format: %(name)s:%(levelname)s: %(message)s

[formatter_detailed]
format: %(name)s:%(levelname)s %(module)s:%(lineno)d: %(message)s

[handler_console]
class: StreamHandler
args: []
formatter: detailed

[handler_file]
class=FileHandler
level=DEBUG
formatter=detailed
args=('output.log', 'w')
filename=output.log
mode=w

[logger_root]
level: INFO
handlers: file
propagate: 1

[Jean-Michel Pichavant]

Post by Ovidiu Deac
file = logging.FileHandler(logFileBasename, 'w')
file.setLevel(logging.INFO)
# set a format which is simpler for console use
formatter = logging.Formatter('%(asctime)s %(name)-12s
%(levelname)-8s %(message)s',)
# tell the handler to use this format
file.setFormatter(formatter)
# add the handler to the root logger
logging.getLogger('').addHandler(file)
logging.getLogger('')
...which also leaves my output file EMPTY.
I'm out of ideas. Can anybody help me with this?
Thanks in advance!
ovidiu

You set le level of your handler, but did not set the level of the
logger itself.
Replace file.setLevel(logging.INFO) by
logging.getLogger().setLevel(logging.INFO)

Log events are matched versus the logger level 1st, then the handler
level (if applicable). Most of the time you don't need to tune your
handler levels.

JM

[Ovidiu Deac]

You set le level of your handler, but did not set the level of the logger
itself.
Replace file.setLevel(logging.INFO) by
logging.getLogger().setLevel(logging.INFO)
Log events are matched versus the logger level 1st, then the handler level
(if applicable). Most of the time you don't need to tune your handler
levels.

Right. Thanks a lot!!!

Now for the second part, any idea why logging.config.fileConfig doesn't work?

Now the logging.conf looks like this:

[formatters]
keys: detailed

[handlers]
keys: console,file

[loggers]
keys: root

[formatter_detailed]
format: %(name)s:%(levelname)s %(module)s:%(lineno)d: %(message)s

[handler_console]
class: StreamHandler
args: []
formatter: detailed

[handler_file]
class=FileHandler
formatter=detailed
args=('output.log', 'w')
filename=output.log
mode=w

[logger_root]
level: INFO
handlers: file

[Jean-Michel Pichavant]

Post by Ovidiu Deac

You set le level of your handler, but did not set the level of the logger
itself.
Replace file.setLevel(logging.INFO) by
logging.getLogger().setLevel(logging.INFO)
Log events are matched versus the logger level 1st, then the handler level
(if applicable). Most of the time you don't need to tune your handler
levels.

Right. Thanks a lot!!!
Now for the second part, any idea why logging.config.fileConfig doesn't work?
[formatters]
keys: detailed
[handlers]
keys: console,file
[loggers]
keys: root
[formatter_detailed]
format: %(name)s:%(levelname)s %(module)s:%(lineno)d: %(message)s
[handler_console]
class: StreamHandler
args: []
formatter: detailed
[handler_file]
class=FileHandler
formatter=detailed
args=('output.log', 'w')
filename=output.log
mode=w
[logger_root]
level: INFO
handlers: file

I'm not sure, I don't use configuration file my loggers.

I don't think the handler_file should have a filename or mode field
though. Try removing them.

JM

[Ovidiu Deac]

Anyway, thanks for the first part.

Anybody else has any idea why using the same configuration file works
when running the tests with nosetests and doesn't work with
logging.config.fileConfig() ?

[Vinay Sajip]

Post by Ovidiu Deac
Anyway, thanks for the first part.
Anybody else has any idea why using the same configuration file works
when running the tests with nosetests and doesn't work withlogging.config.fileConfig() ?

It's probably because the fileConfig code is intended to *replace* any
existing configuration. This means disabling any existing loggers
which are not named explicitly, or not descendants of loggers named
explicitly, in the configuration.

Make sure you call logging.config.fileConfig() before any loggers have
been instantiated in your code, or else ensure that all the top-level
parents of those loggers (i.e. just below the root logger) are defined
in the configuration.

If you have version 2.6 or newer of Python, the fileConfig call has an
optional keyword parameter disable_existing_loggers which has a
default value of True, but which you can set to False to avoid
disabling the existing loggers.

Regards,

Vinay Sajip

[Ovidiu Deac]

It worked. Setting disable_existing_loggers=False fixed my problem.

Thanks to both of you!
Ovidiu

Post by Vinay Sajip

Post by Ovidiu Deac
Anyway, thanks for the first part.
Anybody else has any idea why using the same configuration file works
when running the tests with nosetests and doesn't work withlogging.config.fileConfig() ?

It's probably because the fileConfig code is intended to *replace* any
existing configuration. This means disabling any existing loggers
which are not named explicitly, or not descendants of loggers named
explicitly, in the configuration.
Make sure you call logging.config.fileConfig() before any loggers have
been instantiated in your code, or else ensure that all the top-level
parents of those loggers (i.e. just below the root logger) are defined
in the configuration.
If you have version 2.6 or newer of Python, the fileConfig call has an
optional keyword parameter disable_existing_loggers which has a
default value of True, but which you can set to False to avoid
disabling the existing loggers.
Regards,
Vinay Sajip
--
http://mail.python.org/mailman/listinfo/python-list