Apache Mod-Python - glue between apache and python logging

This is Interesting: Free IT Magazines  
Home > Archive > Apache Mod-Python > October 2005 > glue between apache and python logging





You are viewing an archived Text-only version of the thread. To view this thread in it's original format and/or if you want to reply to this thread please [click here]

Author glue between apache and python logging
Nic Ferrier

2005-10-24, 9:26 am

Hello mod_python developers.

I just joined this list (at the suggestion of Graham Dumpleton) to try
and get you guys to consider adding some glue to connect Python >2.2
logging to Apache's logging.

This means adding a small extra source file to the mod_python
codebase. Here's my example:

# A log handler for mod-python

import logging
from mod_python import apache

class ProxyLogThing:
"""A proxy for default Apache logging."""

def __init__(self):
# No need to do anything.
pass

def log_error(msg, lvl):
apache.log_error(msg, lvl)

class ApacheLogHandler(logging.Handler):
"""A handler class which sends all logging to Apache."""

def __init__(self, ref = None):
"""
Initialize the handler (does nothing)
"""
logging.Handler.__init__(self)

if ref == None:
self.ref = ProxyLogThing()
else:
self.ref = ref

# Set up the thing
self.level_mapping = { }

# self.level_mapping[logging.CRITICAL] = apache.APLOG_ERR
self.level_mapping[logging.ERROR] = apache.APLOG_ERR
self.level_mapping[logging.WARNING] = apache.APLOG_WARNING
self.level_mapping[logging.INFO] = apache.APLOG_INFO
self.level_mapping[logging.debug] = apache.APLOG_DEBUG

def emit(self, record):
"""Emit a record."""
self.ref.log_error(record.msg, record.levelno)

# End


As far as I can see there is no reason not to do this: it does not
create a dependency problem for anyone not using a Python without
logging; it's use is purely optional.

A very good reason for doing it is that it reduces dependancies for
anyone wanting to do this (and it's a very obvious thing to want to do
in any mod_python code).


I wonder what you all think about this?


BTW I'd be happy to maintain and support this if you agreed to include
it.


Nic Ferrier

Jim Gallacher

2005-10-24, 9:26 am

Nic Ferrier wrote:
> Hello mod_python developers.
>
> I just joined this list (at the suggestion of Graham Dumpleton) to try
> and get you guys to consider adding some glue to connect Python >2.2
> logging to Apache's logging.
>
> This means adding a small extra source file to the mod_python
> codebase. Here's my example:
>
> # A log handler for mod-python
>
> import logging
> from mod_python import apache
>
> class ProxyLogThing:
> """A proxy for default Apache logging."""
>
> def __init__(self):
> # No need to do anything.
> pass
>
> def log_error(msg, lvl):
> apache.log_error(msg, lvl)
>
> class ApacheLogHandler(logging.Handler):
> """A handler class which sends all logging to Apache."""
>
> def __init__(self, ref = None):
> """
> Initialize the handler (does nothing)
> """
> logging.Handler.__init__(self)
>
> if ref == None:
> self.ref = ProxyLogThing()
> else:
> self.ref = ref
>
> # Set up the thing
> self.level_mapping = { }
>
> # self.level_mapping[logging.CRITICAL] = apache.APLOG_ERR
> self.level_mapping[logging.ERROR] = apache.APLOG_ERR
> self.level_mapping[logging.WARNING] = apache.APLOG_WARNING
> self.level_mapping[logging.INFO] = apache.APLOG_INFO
> self.level_mapping[logging.debug] = apache.APLOG_DEBUG
>
> def emit(self, record):
> """Emit a record."""
> self.ref.log_error(record.msg, record.levelno)
>
> # End
>
>
> As far as I can see there is no reason not to do this: it does not
> create a dependency problem for anyone not using a Python without
> logging; it's use is purely optional.
>
> A very good reason for doing it is that it reduces dependancies for
> anyone wanting to do this (and it's a very obvious thing to want to do
> in any mod_python code).
>
>
> I wonder what you all think about this?


If the Python logging module is meant to be the standard for logging
then I'm not against it.

However I'm not sure it'll be as simple as Nic's code indicates. I don't
want to expand on my concerns until I have a chance to do some testing
but in the mean time perhaps Nic could give an example of his usage?
(This is a trick question. ;) )

Regards,
Jim




Nick

2005-10-24, 9:26 am

Jim Gallacher wrote:
> Nic Ferrier wrote:
>
[snip][vbcol=seagreen]
> If the Python logging module is meant to be the standard for logging
> then I'm not against it.
>
> However I'm not sure it'll be as simple as Nic's code indicates. I don't
> want to expand on my concerns until I have a chance to do some testing
> but in the mean time perhaps Nic could give an example of his usage?
> (This is a trick question. ;) )


I have done this before, and although I haven't checked this code, it is
as trivial to do as Nic makes it appear (my code was a bit different,
but it did essentially the same thing). On the other hand, I'm not sure
including this code fits with Grisha's philosophy of mod_python being
what it is -- glue between Python and apache -- especially when this is
such a simple exercise to anyone who has read the logging docs.

Nick

Nic Ferrier

2005-10-24, 9:26 am

Nick <nick@dd.revealed.net> writes:

[vbcol=seagreen]
> I have done this before, and although I haven't checked this code, it is
> as trivial to do as Nic makes it appear (my code was a bit different,
> but it did essentially the same thing). On the other hand, I'm not sure
> including this code fits with Grisha's philosophy of mod_python being
> what it is -- glue between Python and apache -- especially when this is
> such a simple exercise to anyone who has read the logging docs.


But that's my point Nick, it's so simple as to be annoying when you
have to do it (it certainly annoyed me when I came to mod_python).

And it's *really* annoying when you come to deploy many webapps based
on mod_python. It's the classic problem with cross app modules - you
have to either maintain a separate installation system absolutely
everywhere you need the module or maintain it's source in many trees.

A nightmare.

I really think the argument about mod_python being minimal does not
apply here.

Nick said it - mod_python is glue between Python and apache - well,
making Python logging work directly to Apache seems like important
glue to me.


Nic

Nick

2005-10-24, 9:26 am

Nic Ferrier wrote:
> Nick <nick@dd.revealed.net> writes:
>
>
>
> But that's my point Nick, it's so simple as to be annoying when you
> have to do it (it certainly annoyed me when I came to mod_python).


I agree, there are several bits of code that are like that.

> I really think the argument about mod_python being minimal does not
> apply here.
>
> Nick said it - mod_python is glue between Python and apache - well,
> making Python logging work directly to Apache seems like important
> glue to me.


And again I renew my argument that there needs to be some kind of
contrib archive that is probably separate from mod_python and
unsupported in the core distribution. Maybe a wiki or code repository
or something to support all the contributions like this. That way all
these neat things can be available to people who are using mod_python,
but not burden the development process of mod_python itself with issues
concerning the constributions.

Nick

Nic Ferrier

2005-10-24, 9:26 am


Nic Ferrier wrote:

Nick <nick@dd.revealed.net> writes:
[vbcol=seagreen]
> And again I renew my argument that there needs to be some kind of
> contrib archive that is probably separate from mod_python and
> unsupported in the core distribution. Maybe a wiki or code repository
> or something to support all the contributions like this. That way all
> these neat things can be available to people who are using mod_python,
> but not burden the development process of mod_python itself with issues
> concerning the constributions.


I agree. But I don't think logging glue should go in it. logging glue
should be in core mod_python because it is glue, not a feature built
on top of Apache or Python, simply a link between the two worlds.

If logging is just available in an addon then developers have still
got the problem of deploying mod_python PLUS pretty much essential
stuff from so and so archive as well as the app.


Nic

Nick

2005-10-24, 9:26 am

Nic Ferrier wrote:
> Nic Ferrier wrote:
>
>
> I agree. But I don't think logging glue should go in it. logging glue
> should be in core mod_python because it is glue, not a feature built
> on top of Apache or Python, simply a link between the two worlds.


Maybe I just don't have enough exposure, but I don't see the logging
module used as ubiquitously as you seem to imply. I could agree with
you if logging was used everywhere, even in Python and its standard
modules. I could be wrong, but I just don't see it.

> If logging is just available in an addon then developers have still
> got the problem of deploying mod_python PLUS pretty much essential
> stuff from so and so archive as well as the app.


Well, while you may see interfacing with the logging module as
"essential" for your work, I just don't see it as a general case. In my
case, I ultimately decided not to use the logging module because it was
more cumbersome than I needed my logging to be. I wanted to be light
and flexible, and anyone using my stuff could implement a logging
handler to use my interfaces, if they liked.

Call it a difference of opinion until someone can change my mind

Nick

Nicolas Lehuen

2005-10-24, 9:26 am

Nic, there is something I need to understand before giving my advice on the
subject. I'm not familiar with the logging API, can you tell me how you
configure Python to use this logging implementation ? Looks like we have to
manipulate configuration object, set up handlers and so on... If so I guess
we'd have to add a word or two in the documentation on the best way to do
this in the mod_python context...

Regards,
Nicolas

2005/10/19, Nic Ferrier <nferrier@tapsellferrier.co.uk>:
>
>
> Nic Ferrier wrote:
>
> Nick <nick@dd.revealed.net> writes:
>
>
> I agree. But I don't think logging glue should go in it. logging glue
> should be in core mod_python because it is glue, not a feature built
> on top of Apache or Python, simply a link between the two worlds.
>
> If logging is just available in an addon then developers have still
> got the problem of deploying mod_python PLUS pretty much essential
> stuff from so and so archive as well as the app.
>
>
> Nic
>


Nicolas Lehuen

2005-10-24, 9:26 am

OK now this is totally weird, we've got a Nic, a Nick and a Nicolas in the
thread, watch out for mass confusion !

2005/10/19, Nicolas Lehuen <nicolas.lehuen@gmail.com>:
>
> Nic, there is something I need to understand before giving my advice on
> the subject. I'm not familiar with the logging API, can you tell me how you
> configure Python to use this logging implementation ? Looks like we have to
> manipulate configuration object, set up handlers and so on... If so I guess
> we'd have to add a word or two in the documentation on the best way to do
> this in the mod_python context...
>
> Regards,
> Nicolas
>
> 2005/10/19, Nic Ferrier <nferrier@tapsellferrier.co.uk>:
>
>


Nic Ferrier

2005-10-24, 9:26 am

Nicolas Lehuen <nicolas.lehuen@gmail.com> writes:

> OK now this is totally weird, we've got a Nic, a Nick and a Nicolas in the
> thread, watch out for mass confusion !


Bah. You got the joke first.


Nic

Nic Ferrier

2005-10-24, 9:26 am

Is everyone here called Nic[h]olas?


Nicolas Lehuen <nicolas.lehuen@gmail.com> writes:

> Nic, there is something I need to understand before giving my advice on the
> subject. I'm not familiar with the logging API, can you tell me how you
> configure Python to use this logging implementation ? Looks like we have to
> manipulate configuration object, set up handlers and so on... If so I guess
> we'd have to add a word or two in the documentation on the best way to do
> this in the mod_python context...


Hmmm... logging is actually very simple if you want it to be.

All you really have to do to use logging from Python is this:

import logging

# then sometime later

logger = logging.getLogger()
logger.debug("a log message")


lot's more things are possible and the logging API is very
configurable.


From an Apache point of view you do need to configure the default
logger in your handler so that it has access to the apache vhost
logger:


hdlr = apache_log_handler.ApacheLogHandler(http)
logging.getLogger().addHandler(hdlr)

once you've done that then any handler which descends from the default
handler (and that's the normal way to do things) will log to Apache.



Nic

Jim Gallacher

2005-10-24, 9:26 am

Nic Ferrier wrote:
> Nicolas Lehuen <nicolas.lehuen@gmail.com> writes:
>
>
>
>
> Bah. You got the joke first.
>
>


Well, this is python, so everyone really should be called Bruce. Maybe
that will help.

Regards,
Bruce

Nick

2005-10-24, 9:26 am

In that case, let us just apply Rule #6 to this situation.

Bruce

Jim Gallacher wrote:
> Nic Ferrier wrote:
>
>
> Well, this is python, so everyone really should be called Bruce. Maybe
> that will help.
>
> Regards,
> Bruce


Nicolas Lehuen

2005-10-24, 9:26 am

2005/10/19, Nic Ferrier <nferrier@tapsellferrier.co.uk>:
>
> Is everyone here called Nic[h]olas?
>
>
> Nicolas Lehuen <nicolas.lehuen@gmail.com> writes:
>
> the
> to
> guess
> do
>
> Hmmm... logging is actually very simple if you want it to be.
>
> All you really have to do to use logging from Python is this:
>
> import logging
>
> # then sometime later
>
> logger = logging.getLogger()
> logger.debug("a log message")
>
>
> lot's more things are possible and the logging API is very
> configurable.
>
>
> From an Apache point of view you do need to configure the default
> logger in your handler so that it has access to the apache vhost
> logger:
>
>
> hdlr = apache_log_handler.ApacheLogHandler(http)
> logging.getLogger().addHandler(hdlr)
>
> once you've done that then any handler which descends from the default
> handler (and that's the normal way to do things) will log to Apache.
>
>
>
> Nic
>


In that case, setting up the logging handler should be done by the user,
making sure that it is set up only once per interpreter, even in the context
of a multi-threaded MPM. It's not a trivial thing ; looks like this is a job
for PythonImport.

So my advice is that if the set up is done by the user, then the logging
handler should be considered as contrib. If you provide a way for mod_python
to directly set up the handler, maybe this could be considered part of
mod_python.

Regards,
Nicolas

Jim Gallacher

2005-10-24, 9:26 am

Nicolas Lehuen wrote:
> 2005/10/19, Nic Ferrier <nferrier@tapsellferrier.co.uk
> <mailto:nferrier@tapsellferrier.co.uk>>:
>
> Is everyone here called Nic[h]olas?
>
>
> Nicolas Lehuen <nicolas.lehuen@gmail.com
> <mailto:nicolas.lehuen@gmail.com>> writes:
>
> advice on the
> how you
> we have to
> so I guess
> way to do
>
> Hmmm... logging is actually very simple if you want it to be.
>
> All you really have to do to use logging from Python is this:
>
> import logging
>
> # then sometime later
>
> logger = logging.getLogger()
> logger.debug("a log message")
>
>
> lot's more things are possible and the logging API is very
> configurable.
>
>
> From an Apache point of view you do need to configure the default
> logger in your handler so that it has access to the apache vhost
> logger:
>
>
> hdlr = apache_log_handler.ApacheLogHandler(http)
> logging.getLogger().addHandler(hdlr)
>
> once you've done that then any handler which descends from the default
> handler (and that's the normal way to do things) will log to Apache.
>
>
>
> Nic
>
>
> In that case, setting up the logging handler should be done by the user,
> making sure that it is set up only once per interpreter, even in the
> context of a multi-threaded MPM. It's not a trivial thing ; looks like
> this is a job for PythonImport.


Except that you won't have a server reference to get the virtual host
configuration. If you are using a custom log for each virtual host,
won't your error messages end up in the wrong log?

> So my advice is that if the set up is done by the user, then the logging
> handler should be considered as contrib. If you provide a way for
> mod_python to directly set up the handler, maybe this could be
> considered part of mod_python.


Here are some further things to consider if anyone wants to persue it.
Consider the following code:

import logging
from mod_python import apache
from proposed_mp_logging_module import ApacheLogHandler

def handler(req)
req.content_type = 'text/plain'
log = logging.getLogger('request')
hdlr = ApacheLogHandler(req)
log.addHandler(hdlr)
log.setLevel(logging.INFO)
msg = 'Its all good'
log.info('%s' % msg)
req.write('check the logs for "%s"' % msg)
apache.OK

All fine and dandy. But isn't logger a singleton? So each time a request
is processed we'll be adding a reference to the request object, which
will never get garbage collected and result in a memory leak.

Furthermore, you can't depend on the request object being valid once
the request processing has completed. At some point request_tp_clear (in
requestobject.c) will get called and request->server will be set to
NULL. (At least I think this is correct). My gut tells me you'll get
some random seg faults.

Also, is there not an assumption that the logger instance is in effect
global? So let's say you change the level in one request such as
log.setLevel(logging.CRITICAL). In mpm-prefork or mpm-worker models
changing the log level will not propagate to the other child processes.
I expect most users will find this confusing.

As I said before I don't think this is as trivial to implement as it
might seem at first blush.

Regards.
Jim


Nic Ferrier

2005-10-24, 9:26 am

Nicolas Lehuen <nicolas.lehuen@gmail.com> writes:

> In that case, setting up the logging handler should be done by the user,
> making sure that it is set up only once per interpreter, even in the context
> of a multi-threaded MPM. It's not a trivial thing ; looks like this is a job
> for PythonImport.


Hang on.

I did NOT ask for mod_python to be altered to set up any logging
handler.

All that I asked is that a module similar to mine be included in
mod_python's dist so that it can be available to programmers by
default.



> So my advice is that if the set up is done by the user, then the logging
> handler should be considered as contrib. If you provide a way for mod_python
> to directly set up the handler, maybe this could be considered part of
> mod_python.


I've been using mod_python (via Debian) for a while and I don't know
anything about a contrib directory.

I presume therefore that it isn't distributed with the package which
is what I am arguing against.

Here's a precis of my argument:

- logging is such a common thing for many projects;

- Python has an official logging API;

- Apache has a logging system that most people using Python logging
will want to interface to

- code to allow Python logging and Aapache logging to be glued
together is trivial

- if everyone has to write trivial logging code over and over again
that's a bad thing



I am NOT asking the mod_python people to spec any wildly strange code

I am NOT asking for mod_python to be altered, except in terms of the
files that are distributed with it

I am NOT even asking that the maintainers take on new code (I'll
happily maintain it and do whatever needs to be done to import it into
your code base)...


Sheesh guys. This seemed like a no brainer to me.


Nic

Nic Ferrier

2005-10-24, 9:26 am

Nick <nick@dd.revealed.net> writes:

> Maybe I just don't have enough exposure, but I don't see the logging
> module used as ubiquitously as you seem to imply. I could agree with
> you if logging was used everywhere, even in Python and its standard
> modules. I could be wrong, but I just don't see it.


Ok. I think this is a false argument as well.

Python's official API has the logging package. It has been there since
2.3 (and actually lots of projects did use it since 2.1 I think).

logging is not normally used by API code, it's application specific,
so you're unlikely to find it being used by the Python APIs.

Why does this need more imperative evidence to convince you? It's the
official logging module for Python.

Wanna roll your own?

Well, you can do that but you probably shouldn't for all the reasons
that you probably shouldn't roll your own pickler: readability, reuse,

[Note: I did say: *probably* shouldn't]


> Well, while you may see interfacing with the logging module as
> "essential" for your work, I just don't see it as a general case. In my
> case, I ultimately decided not to use the logging module because it was
> more cumbersome than I needed my logging to be. I wanted to be light
> and flexible, and anyone using my stuff could implement a logging
> handler to use my interfaces, if they liked.


Light and flexible? More light than:

import logging
logging.getLogger().log("some message")

and more flexible than Python logging? Have you read the doc?



> Call it a difference of opinion until someone can change my mind


I believe I'm trying to change your mind.

But it's difficult to change your mind if you say "prove that logging
is the most widely used logging available and then I'll think about it
but I don't use it anyway because I wrote my own".

Unfortunately I have to argue from the position that logging is
officially part of the Python language.


Nic

Nicolas Lehuen

2005-10-24, 9:26 am

- good thinking about the virtual host problem...

- I would not add the handler to the 'request' logger ; like Nic or Nick or
Bruce said, this is not required, the 'request' logger inherits his handlers
from the root logger. This would ease things a little bit.

- Anyway, my point is the same as yours : setting it up properly is far from
trivial. The simplicity of the handler code should not mask the complexity
of the setup.

One thing to remember : every piece of code we introduce into mod_python is
a liability. We'll have to support it and I can't wait for having to solve
setup problems of people asking the list "where are my log entries going ?"
or "my log entries are repeated multiple times in the Apache log".

So, either we have a full treatment of all the problems this logging handler
may bring, or we just have this little Pandora box lying somewhere in the
contrib department, along with SQLiteSession .

You guys must find it funny that I write this after having proposed
SQLiteSession, but I think I've understood the point now . It will be time
to add random features here and there when we'll be bored to death because
no one is posting to the list about any problem.

Regards,
Nicolas

2005/10/19, Jim Gallacher <jg.lists@sympatico.ca>:
>
> Nicolas Lehuen wrote:
>
> Except that you won't have a server reference to get the virtual host
> configuration. If you are using a custom log for each virtual host,
> won't your error messages end up in the wrong log?
>
>
> Here are some further things to consider if anyone wants to persue it.
> Consider the following code:
>
> import logging
> from mod_python import apache
> from proposed_mp_logging_module import ApacheLogHandler
>
> def handler(req)
> req.content_type = 'text/plain'
> log = logging.getLogger('request')
> hdlr = ApacheLogHandler(req)
> log.addHandler(hdlr)
> log.setLevel(logging.INFO)
> msg = 'Its all good'
> log.info('%s' % msg)
> req.write('check the logs for "%s"' % msg)
> apache.OK
>
> All fine and dandy. But isn't logger a singleton? So each time a request
> is processed we'll be adding a reference to the request object, which
> will never get garbage collected and result in a memory leak.
>
> Furthermore, you can't depend on the request object being valid once
> the request processing has completed. At some point request_tp_clear (in
> requestobject.c) will get called and request->server will be set to
> NULL. (At least I think this is correct). My gut tells me you'll get
> some random seg faults.
>
> Also, is there not an assumption that the logger instance is in effect
> global? So let's say you change the level in one request such as
> log.setLevel(logging.CRITICAL). In mpm-prefork or mpm-worker models
> changing the log level will not propagate to the other child processes.
> I expect most users will find this confusing.
>
> As I said before I don't think this is as trivial to implement as it
> might seem at first blush.
>
> Regards.
> Jim
>
>


Nic Ferrier

2005-10-24, 9:26 am

Nicolas Lehuen <nicolas.lehuen@gmail.com> writes:

> One thing to remember : every piece of code we introduce into mod_python is
> a liability. We'll have to support it and I can't wait for having to solve
> setup problems of people asking the list "where are my log entries going ?"
> or "my log entries are repeated multiple times in the Apache log".
>
> So, either we have a full treatment of all the problems this logging handler
> may bring, or we just have this little Pandora box lying somewhere in the
> contrib department, along with SQLiteSession .


You might expect me to argue against this, so here goes:

I think you're right - but this code is an exception.

module logging is official Python API. Apache logging maps really
easily onto official Python logging (yes - there are issues - but only
the same issues as with any multi-programming).

We could find all the things that could be done with logging. We
could. But that would be a very big project in itself.

Adding optional glue to connect Python logging to Apache logging is
not complex.

And I have already offered to maintain it. Search for me on Google if
you fear I am some fly by night flibberty gibbet who will run away
when the first question is asked.



Nic

Nic Ferrier

2005-10-24, 9:27 am

Jim Gallacher <jg.lists@sympatico.ca> writes:

> Nicolas Lehuen wrote:
>
> Except that you won't have a server reference to get the virtual host
> configuration. If you are using a custom log for each virtual host,
> won't your error messages end up in the wrong log?


I was not arguing for a mod_python managed logging creation. Only that
the mod_python distribution include a module that provides the glue
between Apache logging and Python logging.

Having mod_python create the logger would not be right IMHO because it
is unnecessary for code that doesn't use logging or uses Apache
logging directly.


> Here are some further things to consider if anyone wants to persue it.
> Consider the following code:
>
> import logging
> from mod_python import apache
> from proposed_mp_logging_module import ApacheLogHandler
>
> def handler(req)
> req.content_type = 'text/plain'
> log = logging.getLogger('request')
> hdlr = ApacheLogHandler(req)
> log.addHandler(hdlr)
> log.setLevel(logging.INFO)
> msg = 'Its all good'
> log.info('%s' % msg)
> req.write('check the logs for "%s"' % msg)
> apache.OK
>
> All fine and dandy. But isn't logger a singleton? So each time a request
> is processed we'll be adding a reference to the request object, which
> will never get garbage collected and result in a memory leak.


There might be a fault with my design here. To help me understand what
you're saying can you confirm that when you say:

"But isn't logger a singleton"

do you mean:

"But isn't 'log' a singleton?" (ie: 'log' refers to the instance
variable in your example)


> Furthermore, you can't depend on the request object being valid once
> the request processing has completed. At some point request_tp_clear (in
> requestobject.c) will get called and request->server will be set to
> NULL. (At least I think this is correct). My gut tells me you'll get
> some random seg faults.


There are only two ways this can happen I think:

1. the user saves the logger for later (maybe in a thread) and tries
to log after the request has finished

This would be user error and therefore acceptable IMHO.

I should point out that this is unlikely to happen since loggers
tend to be very local objects with small scopes.

2. the logging record doesn't get flushed before the request has
completed so that when it is flushed the correct state is no longer
available.

This is also possible, clearly it would be a bug because the
logging record should be flushed immediately (if that's the
implementation of the handler)


> Also, is there not an assumption that the logger instance is in effect
> global? So let's say you change the level in one request such as
> log.setLevel(logging.CRITICAL). In mpm-prefork or mpm-worker models
> changing the log level will not propagate to the other child processes.
> I expect most users will find this confusing.


Not sure why you think that.

If mod_python included a module based on my design there would be a
clear understanding that it was specifically for request derived
logging (the most common case).

It's particularly clear from my design because it takes a request as
an argument. You couldn't create one of my log handlers globally for
example.

Also the natural thing to do with logging is to have one per unit of
code.


> As I said before I don't think this is as trivial to implement as it
> might seem at first blush.


I think it has all of the same problems as any other multi-programming
(threads or processes) code. It's true that a lot of users don't
understand those issues but that's not exclusive to logging.


Nic

Nick

2005-10-24, 9:27 am

Nic Ferrier wrote:
> But it's difficult to change your mind if you say "prove that logging
> is the most widely used logging available and then I'll think about it
> but I don't use it anyway because I wrote my own".


Well, that's not what I said. What I said was:

1. I'm not convinced that a logger handler should be included in
mod_python just because it's a standard module. A lot of packages out
there that have logging facilities don't necessarily use logger. Even
though it's part of the Python distribtion, that doesn't make it
uniquitous in its use. mod_python exposes apache's logging facility in
using interface that apache provides. I think that's the goal of
mod_python, to (1) provide access to apache's API and (2) provide
dispatching for handlers.

2. My counterargument to the logging interface as being "essential" is
that I neither use the logging module nor want to use it. I tried to
use it, but the implementation required a lot of overhead (mostly due to
threading issues and access to the right req object). YMMV, but my
experience led me to create a thinner wrapper around apache.log_error
that was simply easier to use and maintain. That really has nothing to
do with whether or not

In terms of changing my mind, that has to do with whether or not I
believe it should be part of the core mod_python distribution. And I
still think it should not. I still think it falls under the umbrella of
contributed code, just as if it was an implementation that utilized
cgitb or SimpleXMLRPCServer, both of which are standard modules and
arguably pretty darn useful in mod_python development.

Please note that I also disagree with including the publisher and psp
handlers as part of the core distribution, but, well, we can't turn back
the clock on that ;-) And besides, I'm probably one of the few here who
don't use them, making my opinion on that matter a minority view.

> Unfortunately I have to argue from the position that logging is
> officially part of the Python language.


Respectfully, I don't think that has anything to do with it. There's a
lot that can be done with only the official parts of the Python language
that aren't included in mod_python but left as an option for the user to
implement. Recently a bid to include a WSGI implementation for
mod_python was shot down, which is a Python PEP and something I thought
would have been pretty neat to include. Regardless of Grisha's personal
feelings on that (and I have a pretty good idea of what they are ;-)), I
think it was ultimately the right decision for mod_python.

Nick

Jim Gallacher

2005-10-24, 9:27 am

Nic Ferrier wrote:
> All that I asked is that a module similar to mine be included in
> mod_python's dist so that it can be available to programmers by
> default.


Yes, I understand this. I just think if the decision was made to include
this feature it should be rock solid. I've not used the Python logging
module, but a cursory glance leads me to believe that it might be easy
create a bad implementation.

> I've been using mod_python (via Debian) for a while and I don't know
> anything about a contrib directory.


This is where we apply rule #6. ;) (Thanks for that Nick. It made me
chuckle).

You have not heard about a contrib directory because it does not exist.
This is just an idea we've been tossing around to address the question
of how to accomodate new features without adding bloat and complexity to
mod_python. (And before you get excited Nic - I am *not* suggesting your
proposal is bloat).

> Here's a precis of my argument:
>
> - logging is such a common thing for many projects;
>
> - Python has an official logging API;
>
> - Apache has a logging system that most people using Python logging
> will want to interface to
>
> - code to allow Python logging and Aapache logging to be glued
> together is trivial
>
> - if everyone has to write trivial logging code over and over again
> that's a bad thing


And I agree with all these points except that I don't think it's trivial
to get it right. In fact, that it is *not* trivial may be best argument
for inclusion in mod_python. Having everyone write seemingly trivial
logging code which causes mod_python memory leaks or segfaults
ultimately reflects poorly on mod_python, even if it's the user's own
bad code.

> Sheesh guys. This seemed like a no brainer to me.

So is that your problem or ours? (Note the smiley - this meant to be
funny).

Regards,
Jim

Jorey Bump

2005-10-24, 9:27 am

Where do I file a documentation bug? Rule #6 appears to be missing. ;)

Sydney Nolan

Nick wrote:[vbcol=seagreen]
> In that case, let us just apply Rule #6 to this situation.
>
> Bruce
>
> Jim Gallacher wrote:


Jim Gallacher

2005-10-24, 9:27 am

Nic Ferrier wrote:
> Jim Gallacher <jg.lists@sympatico.ca> writes:
>
>
> There might be a fault with my design here. To help me understand what
> you're saying can you confirm that when you say:
>
> "But isn't logger a singleton"
>
> do you mean:
>
> "But isn't 'log' a singleton?" (ie: 'log' refers to the instance
> variable in your example)


I meant log but perhaps should have said logging. All log handlers are
stored in the module level variable logging.root. Take a look at
logging.__init__.py.

>

My gut was right. Your current version segfaults (using mpm-prefork). It
might work if you register a cleanup to remove the reference to your
logging handler (untested):

req.register_cleanup(log.removeHandler, hdlr)

The problem here is that we are depending on the user to add that line
to their code to avoid the segfault. I don't like the idea of including
code in mod_python which may result in a segfault, even if the user is
warned of the dangers in the docs.
[vbcol=seagreen]
>
> There are only two ways this can happen I think:
>
> 1. the user saves the logger for later (maybe in a thread) and tries
> to log after the request has finished
>
> This would be user error and therefore acceptable IMHO.
>
> I should point out that this is unlikely to happen since loggers
> tend to be very local objects with small scopes.


Loggers have module level scope. When you add a handler you are adding
it to logging.root. In a given process, each call to
log.addHandler(hdlr) adds another ApacheLogHandler instance with it's
associated request object. Thus you would expect that when you try to
log an error you would see multiple messages in the apache log, but
mod_python actually segfaults instead, since most request objects
(except the current one) are likely invalid. Thus the need to remove the
handler at the end of the request as mentioned above.

> 2. the logging record doesn't get flushed before the request has
> completed so that when it is flushed the correct state is no longer
> available.
>
> This is also possible, clearly it would be a bug because the
> logging record should be flushed immediately (if that's the
> implementation of the handler)


The problem is not with the current request. That will be ok as long as
you are logging your message prior to the end of the request processing
phase. The problem is with the references to old requests being held by
logging.root.

>
>
>
>
> Not sure why you think that.


Which part? - That users will want to change the log level or that
they'll get confused? ;) Or the global part?

>
> If mod_python included a module based on my design there would be a
> clear understanding that it was specifically for request derived
> logging (the most common case).
>
> It's particularly clear from my design because it takes a request as
> an argument. You couldn't create one of my log handlers globally for
> example.


It wasn't clear to me. The request argument for
ApacheLogHandler._init__() is optional and when it's missing you create
an instance of ProxyLogThing. ProxyLogThing.log_error calls
apache.log_error which suggests to me this could be be used outside of a
request.

> Also the natural thing to do with logging is to have one per unit of
> code.
>
>
>
>
> I think it has all of the same problems as any other multi-programming
> (threads or processes) code. It's true that a lot of users don't
> understand those issues but that's not exclusive to logging.


Yep. It sure messes me up, and trying to do things inside of apache just
makes everything more complicated.

Just to be clear Nic, I'm not fighting you on the *idea* of including
your ApacheLogHandler - I may even be in favour of it. I'm just pointing
out some potential problems. I have a few more up my sleeve but I want
to test them before commenting.

Regards,
Jim

David Fraser

2005-10-24, 9:27 am

Jim Gallacher wrote:

> Nic Ferrier wrote:
>
>
> Yes, I understand this. I just think if the decision was made to
> include this feature it should be rock solid. I've not used the python
> logging module, but a cursory glance leads me to believe that it might
> be easy create a bad implementation.
>
>
> This is where we apply rule #6. ;) (Thanks for that Nick. It made me
> chuckle).
>
> You have not heard about a contrib directory because it does not
> exist. This is just an idea we've been tossing around to address the
> question of how to accomodate new features without adding bloat and
> complexity to mod_python. (And before you get excited Nic - I am *not*
> suggesting your proposal is bloat).
>
>
> And I agree with all these points except that I don't think it's
> trivial to get it right. In fact, that it is *not* trivial may be best
> argument for inclusion in mod_python. Having everyone write seemingly
> trivial logging code which causes mod_python memory leaks or segfaults
> ultimately reflects poorly on mod_python, even if it's the user's own
> bad code.


Absolutely. I would be +1 on including a module that handles logging
with all the management required for it to work properly in a mod_python
context.

> Regards,
> Jim


Didn't we agree that everyone should be called Nic* or Bruce?

David (Oops!)

Nicolas Lehuen

2005-10-24, 9:27 am

2005/10/20, David Fraser <davidf@sjsoft.com>:
>
> Jim Gallacher wrote:
>
>
> Absolutely. I would be +1 on including a module that handles logging
> with all the management required for it to work properly in a mod_python
> context.
> Regards,
>


That's my position, too. That's what I meant by "either we get it thoroughly
right, or we don't integrate it into mod_python".

Regards,
Nicolas

Graham Dumpleton

2005-10-24, 9:27 am


On 20/10/2005, at 5:49 PM, Nicolas Lehuen wrote:

>
> best
> seemingly
> segfaults
> own
>
> Absolutely. I would be +1 on including a module that handles logging
> with all the management required for it to work properly in a
> mod_python
> context.
> Regards,
>
> That's my position, too. That's what I meant by "either we get it
> thoroughly right, or we don't integrate it into mod_python".


If logging is going to be addressed, it may be worthwhile at the
same time looking at how sys.stdout/sys.stderr (especially the
latter) behave in the context of mod_python. This is because not
all modules use logging and instead use sys.stderr. Problem is
that sometimes there are issues with this being flushed out properly
and it only ends up appearing in the Apache log file when Apache
is shutdown. This can be confusing when debugging problems
as the messages don't appear in the log straight away.

Graham

Nic Ferrier

2005-10-24, 9:27 am

Jim Gallacher <jg.lists@sympatico.ca> writes:

>
> My gut was right. Your current version segfaults (using mpm-prefork). It
> might work if you register a cleanup to remove the reference to your
> logging handler (untested):
>
> req.register_cleanup(log.removeHandler, hdlr)
>
> The problem here is that we are depending on the user to add that line
> to their code to avoid the segfault. I don't like the idea of including
> code in mod_python which may result in a segfault, even if the user is
> warned of the dangers in the docs.


Ok. I found the problem too... I was going to add an end of request
clean up to make logging rather like resource usage:

def handler(http):
hdlr = apache_log_handler.ApacheLogHandler(http)
logging.getLogger().addHandler(hdlr)
logger = logging.getLogger("webapp")
Nic Ferrier

2005-10-24, 9:27 am

Jim Gallacher <jg.lists@sympatico.ca> writes:

> My gut was right. Your current version segfaults (using mpm-prefork). It
> might work if you register a cleanup to remove the reference to your
> logging handler (untested):
>
> req.register_cleanup(log.removeHandler, hdlr)
>
> The problem here is that we are depending on the user to add that line
> to their code to avoid the segfault. I don't like the idea of including
> code in mod_python which may result in a segfault, even if the user is
> warned of the dangers in the docs.


Here's a new version of my logging module which fixes these problems.


# A log handler for mod-python

import logging
from mod_python import apache


class ApacheLogHandler(logging.Handler):
"""A handler class which sends all logging to Apache."""

def __init__(self, request):
"""
Initialize the handler (does nothing)
"""
logging.Handler.__init__(self)
self.request = request

def cleanup(data = None):
self.request = None

request.register_cleanup(cleanup)

# Set up the thing
self.level_mapping = { }

self.level_mapping[logging.CRITICAL] = apache.APLOG_CRIT
self.level_mapping[logging.ERROR] = apache.APLOG_ERR
self.level_mapping[logging.WARNING] = apache.APLOG_WARNING
self.level_mapping[logging.INFO] = apache.APLOG_INFO
self.level_mapping[logging.debug] = apache.APLOG_DEBUG

def emit(self, record):
"""Emit a record."""
msg = self.format(record)
if self.request != None:
self.request.log_error(msg, self.level_mapping[record.levelno])

# We *could* log to apache here:
#else:
# apache.log(msg)


# End

There is one remaining problem that I am aware of. When you do:

logger = logging.getLogger("webapp")

you are always gauranteed to get the same logger. That's bad in a
multi-programming environment.

The traditional approach to this is to create your logger with a
unique name, eg:

logger = logging.getLogger("webapp" + thread_id)

But clearly we'd be relying on users to do that.

I could come up with a logging factory to mitigate that.



Nic

Jim Gallacher

2005-10-24, 9:27 am

Nic Ferrier wrote:
> Jim Gallacher <jg.lists@sympatico.ca> writes:
>
>
>
>
> Here's a new version of my logging module which fixes these problems.
>
>
> # A log handler for mod-python
>
> import logging
> from mod_python import apache
>
>
> class ApacheLogHandler(logging.Handler):
> """A handler class which sends all logging to Apache."""
>
> def __init__(self, request):
> """
> Initialize the handler (does nothing)
> """
> logging.Handler.__init__(self)
> self.request = request
>
> def cleanup(data = None):
> self.request = None
>
> request.register_cleanup(cleanup)
>
> # Set up the thing
> self.level_mapping = { }
>
> self.level_mapping[logging.CRITICAL] = apache.APLOG_CRIT
> self.level_mapping[logging.ERROR] = apache.APLOG_ERR
> self.level_mapping[logging.WARNING] = apache.APLOG_WARNING
> self.level_mapping[logging.INFO] = apache.APLOG_INFO
> self.level_mapping[logging.debug] = apache.APLOG_DEBUG
>
> def emit(self, record):
> """Emit a record."""
> msg = self.format(record)
> if self.request != None:
> self.request.log_error(msg, self.level_mapping[record.levelno])
>
> # We *could* log to apache here:
> #else:
> # apache.log(msg)
>
>
> # End


There is a typo in your code: s/logging.debug/logging.DEBUG/

Beyond that it still segfaults for me. The other problem is that you are
not removing the handler instance from the logging instance so you still
have a memory leak. 100k requests would result in 100k handler
instances. Oh, and there might be a bit of a performance issue when
emit() gets fired 100k times. ;) Or should I assume that the user will
still be required to include req.register_cleanup(log.removeHandler,
hdlr) in their code?

> There is one remaining problem that I am aware of. When you do:
>
> logger = logging.getLogger("webapp")
>
> you are always gauranteed to get the same logger. That's bad in a
> multi-programming environment.
>
> The traditional approach to this is to create your logger with a
> unique name, eg:
>
> logger = logging.getLogger("webapp" + thread_id)


It may be better to use the interpreter name.

> But clearly we'd be relying on users to do that.


Those darn users again!

> I could come up with a logging factory to mitigate that.


I'm not sure what you have in mind, but would the usage be the same as
for the standard logging module? One of the advantages of following the
standard is that people can write familiar looking code and things just
work they expect.

Regards,
Jim

Nick

2005-10-24, 9:27 am

Jim Gallacher wrote:
> Beyond that it still segfaults for me. The other problem is that you are
> not removing the handler instance from the logging instance so you still
> have a memory leak. 100k requests would result in 100k handler
> instances. Oh, and there might be a bit of a performance issue when
> emit() gets fired 100k times. ;) Or should I assume that the user will
> still be required to include req.register_cleanup(log.removeHandler,
> hdlr) in their code?


Not sure if this will help, but in my implementation I registered my hander
on the root logger as global code in the handler module, not for each
request. In that case I used a threading.local to keep track of req, which
I had to register and free for each request of course. I couldn't get
around the minimal bookkeeping required of registering the req object on
each request, though like Nic's code, I registered a cleanup in a closure to
handle the freeing.

Alternatively, you can register the server and use apache.log_error with a
server object, which should not leak. Also, if you don't care about logging
to a particular server, you can, of course, just call apache.log_error
without a server argument.

Nick


Nic Ferrier

2005-10-24, 9:27 am

Jim Gallacher <jg.lists@sympatico.ca> writes:

> There is a typo in your code: s/logging.debug/logging.DEBUG/


Got me. It ran for me though...


> Beyond that it still segfaults for me.


I can't get it to segfault.

Can you share your test?


> The other problem is that you are not removing the handler instance
> from the logging instance so you still have a memory leak. 100k
> requests would result in 100k handler instances. Oh, and there might
> be a bit of a performance issue when emit() gets fired 100k
> times. ;)


Good point... here's another one:


# A log handler for mod-python

import logging
from mod_python import apache


class ApacheLogHandler(logging.Handler):
"""A handler class which sends all logging to Apache."""

def __init__(self, request):
"""
Initialize the handler (does nothing)
"""
logging.Handler.__init__(self)
self.request = request

def cleanup(data = None):
self.request = None
logging.getLogger().removeHandler(self)

request.register_cleanup(cleanup)

# Set up the thing
self.level_mapping = { }

self.level_mapping[logging.CRITICAL] = apache.APLOG_CRIT
self.level_mapping[logging.ERROR] = apache.APLOG_ERR
self.level_mapping[logging.WARNING] = apache.APLOG_WARNING
self.level_mapping[logging.INFO] = apache.APLOG_INFO
self.level_mapping[logging.DEBUG] = apache.APLOG_DEBUG

def emit(self, record):
"""Emit a record."""
msg = self.format(record)
if self.request != None:
self.request.log_error(msg, self.level_mapping[record.levelno])

# We *could* log to apache here:
#else:
# apache.log(msg)


# End


Nic said:

>
> It may be better to use the interpreter name.


Yeah... thread_id was just to intimate that it was unique for some
multi-programming concept.


>
> Those darn users again!
>
>
> I'm not sure what you have in mind, but would the usage be the same as
> for the standard logging module? One of the advantages of following the
> standard is that people can write familiar looking code and things just
> work they expect.


Well, most of the advantage of doing this is that you can interface
logging code to mod_python without having to change it. Just have your
handler set up the logging glue, the rest just works.

So having to use another factory method instead of the normal logging
factory method in your handler is not necessarily a big deal.

But in fact, the unique ness isn't such a big deal. There is a lock
inside the handlers so they shouldn't trample on each other. Needs
testing clearly.


Nic

Graham Dumpleton

2005-10-24, 9:27 am


On 21/10/2005, at 2:41 AM, Nic Ferrier wrote:

>
> There is one remaining problem that I am aware of. When you do:
>
> logger = logging.getLogger("webapp")
>
> you are always gauranteed to get the same logger. That's bad in a
> multi-programming environment.
>
> The traditional approach to this is to create your logger with a
> unique name, eg:
>
> logger = logging.getLogger("webapp" + thread_id)
>
> But clearly we'd be relying on users to do that.
>
> I could come up with a logging factory to mitigate that.


Needs to be based on more than thread ID. An internal redirect can
cause a new request handler to be triggered using the same thread.
Thus, rather than thread ID, it probably needs to be the Python ID of
the request object, ie., id(req).

This should work as a new request object is created for the internal
redirect.

Graham

Jim Gallacher

2005-10-24, 9:27 am

Nic Ferrier wrote:
> Jim Gallacher <jg.lists@sympatico.ca> writes:
>
>
>
>
> Got me. It ran for me though...
>
>
>
>
>
> I can't get it to segfault.
>
> Can you share your test?


Sure, but it's not doing anything fancy.

Debian Sid, apache2-mpm-prefork 2.0.54, Python 2.3.5, mod_python 3.2.2b.
The ApacheLogHandler class is in module mod_python/future/mplog.py
Using mod_python.publisher handler:


test.py
-------

from mod_python.future.mplog import ApacheLogHandler
import logging

def index(req):
return '''<html><body>
<a href="test.py/segfault">seg fault</a><br />
<a href="test.py/no_segfault">no seg fault</a><br />
</body></html>'''

def segfault(req):
log = logging.getLogger()
hdlr = ApacheLogHandler(req)
log.addHandler(hdlr)
log.critical('test.segfault: seg fault?')
return '''removeHandler cleanup NOT registered:
check the log for a segfault'''

def no_segfault(req):
log = logging.getLogger()
hdlr = ApacheLogHandler(req)
log.addHandler(hdlr)
req.register_cleanup(log.removeHandler, hdlr)
log.critical('test.no_segfault: seg fault?')
return '''removeHandler cleanup registered:
check the log for a segfault'''

>
>
> Good point... here's another one:
>
>
> # A log handler for mod-python
>
> import logging
> from mod_python import apache
>
>
> class ApacheLogHandler(logging.Handler):
> """A handler class which sends all logging to Apache."""
>
> def __init__(self, request):
> """
> Initialize the handler (does nothing)
> """
> logging.Handler.__init__(self)
> self.request = request
>
> def cleanup(data = None):
> self.request = None
> logging.getLogger().removeHandler(self)
>
> request.register_cleanup(cleanup)
>
> # Set up the thing
> self.level_mapping = { }
>
> self.level_mapping[logging.CRITICAL] = apache.APLOG_CRIT
> self.level_mapping[logging.ERROR] = apache.APLOG_ERR
> self.level_mapping[logging.WARNING] = apache.APLOG_WARNING
> self.level_mapping[logging.INFO] = apache.APLOG_INFO
> self.level_mapping[logging.DEBUG] = apache.APLOG_DEBUG
>
> def emit(self, record):
> """Emit a record."""
> msg = self.format(record)
> if self.request != None:
> self.request.log_error(msg, self.level_mapping[record.levelno])
>
> # We *could* log to apache here:
> #else:
> # apache.log(msg)
>
>
> # End


This version does not segfault, and should take care of the memory leak
but only for the root logger. If the user specifies a different logger...

log = logging.getLogger('myLooger')

.... we are back to the potential segfault problems.

I also want to mention that there will be a performance impact in using
logging since only one thread can access the logging object at a time.
I'm including this comment now just in case I forget later. Not a big
deal but it is something that should be considered for a high traffic
site and is an argument for not using the standard Python logging
facility internally in mod_python... which Nic was *not* asking for
anyway.

Regards,
Jim

Graham Dumpleton

2005-10-24, 9:27 am

Nick wrote ..
> Jim Gallacher wrote:
> are
>
> Not sure if this will help, but in my implementation I registered my hander
> on the root logger as global code in the handler module, not for each
> request. In that case I used a threading.local to keep track of req, which
> I had to register and free for each request of course. I couldn't get
> around the minimal bookkeeping required of registering the req object on
> each request, though like Nic's code, I registered a cleanup in a closure
> to
> handle the freeing.
>
> Alternatively, you can register the server and use apache.log_error with
> a
> server object, which should not leak. Also, if you don't care about logging
> to a particular server, you can, of course, just call apache.log_error
> without a server argument.


If I understand you correctly, you are probably managing this in the same
way as I think is possibly a much better way than what is currently being
discussed.

That is, a global log handler instance is created once only. No instance per
request handler invocation.

As you point out you need though to do caching of request objects. I have
previously posted on a safe way of doing this which works for internal
redirects. See:

http://www.modpython.org/pipermail/...ber/019071.html

Other solutions I have seen people describe for request caching didn't
consider internal redirects properly. One also can't use thread local
storage as Python 2.3 doesn't support it.

I have already pointed out how this sort of request caching will probably
be needed in mod_python 3.3 when various of the problems with the
module loading system hopefully will be fixed. Thus, any logger system
could harness what would then be builtin functionality at no cost.

In terms of seamless integration, I am coming to the conclusion that
having mod_python internally create the single global log handler as part
of mod_python.apache being imported would be best. It only gets done
once, so insignificant overhead. Any code therefore doesn't need to
worry about that and just needs to get the logger and log their messages.
Beyond the creation of the one log handler, there is no overhead unless
handlers actually use logging, as the request caching will need to be
done for other reasons anyway associated with module importing.

What would happen is that when the log handler gets called, it would use
the request cache to look up the request object pertinent to the thread
at that time. When it gets that, it logs the message through the req
object. If a message is being logged by a distinct thread and not the
request handler thread, it would be logged via "apache.log_error()".

Apart from the benefit of individual request handlers not having to create
log handler instances and all the cleanup problems with that etc, this
logging mechanism is still usuable from global scope of a module and
messages logged at that point when a module is being imported due
to a request, will still be logged against the request object.

Hopefully everyone follows what I am talking about. I will try and get
together a working example today of what I am talking about, but Nick,
you may want to consider posting your code and how you are using it
as it probably will not be too different.

Graham

Nic Ferrier

2005-10-24, 9:27 am

"Graham Dumpleton" <grahamd@dscpl.com.au> writes:

> That is, a global log handler instance is created once only. No instance per
> request handler invocation.
>
> As you point out you need though to do caching of request objects. I have
> previously posted on a safe way of doing this which works for internal
> redirects. See:
>
> http://www.modpython.org/pipermail/...ber/019071.html
>
> Other solutions I have seen people describe for request caching didn't
> consider internal redirects properly. One also can't use thread local
> storage as Python 2.3 doesn't support it.
>
> I have already pointed out how this sort of request caching will probably
> be needed in mod_python 3.3 when various of the problems with the
> module loading system hopefully will be fixed. Thus, any logger system
> could harness what would then be builtin functionality at no cost.


This is interesting... how does it play with non-thread mpms?


> In terms of seamless integration, I am coming to the conclusion that
> having mod_python internally create the single global log handler as part
> of mod_python.apache being imported would be best. It only gets done
> once, so insignificant overhead. Any code therefore doesn't need to
> worry about that and just needs to get the logger and log their messages.
> Beyond the creation of the one log handler, there is no overhead unless
> handlers actually use logging, as the request caching will need to be
> done for other reasons anyway associated with module importing.


I specifically rejected that option myself.

Programmers may or may not want to redirect logging through Apache. If
mod_python used the system you describe there would either have to be:

1. config syntax to allow module 'logging' glue to be turned off

2. removal of the apache log handler in all code that didn't want it

I don't like either of those.

I can think of lots and lots of reasons why code using logging
wouldn't want to log to Apache.


> Apart from the benefit of individual request handlers not having to create
> log handler instances and all the cleanup problems with that etc,


I don't believe it is onerous to have to specifically attach the
Apache log handling glue in the handler.

I think I have solved the cleanup problems.

My module makes logging available like any other cost based resource
(eg: database connections).


> this logging mechanism is still usuable from global scope of a
> module and messages logged at that point when a module is being
> imported due to a request, will still be logged against the request
> object.


Another advantage of your system is that the logging config file
syntax could be used to assign loggers (I think).



Nic

Graham Dumpleton

2005-10-24, 9:27 am

Graham Dumpleton wrote ..
> Hopefully everyone follows what I am talking about. I will try and get
> together a working example today of what I am talking about, but Nick,
> you may want to consider posting your code and how you are using it
> as it probably will not be too different.


Okay, here is my suggested code. I have bundled it up as a tar file as a
complete working example as easier than explaining how to set it up for
testing. The .htaccess file sets up two handler phases, ie. separates
out the request caching bits as the intent would be that that all be
done in mod_python and be transparent anyway.

Note that I suspect that the log level mapping as described so far isn't
adequate as log levels can be arbitrary and may fall between the
predefined levels.

Graham

Graham Dumpleton

2005-10-24, 9:27 am

Graham Dumpleton wrote ..
> Graham Dumpleton wrote ..
>
> Okay, here is my suggested code. I have bundled it up as a tar file as
> a
> complete working example as easier than explaining how to set it up for
> testing. The .htaccess file sets up two handler phases, ie. separates
> out the request caching bits as the intent would be that that all be
> done in mod_python and be transparent anyway.
>
> Note that I suspect that the log level mapping as described so far isn't
> adequate as log levels can be arbitrary and may fall between the
> predefined levels.


Here is an alternate "mptest.py" example which shows how logging can
still work at global level.

from mod_python import apache
import logging

log = logging.getLogger("mod_python")
log.warning("importing handler")

def handler(req):
log.warning("running handler")
req.content_type = 'text/plain'
req.send_http_header()
req.write('hello\n')
return apache.OK


Graham Dumpleton

2005-10-24, 9:27 am

Nic Ferrier wrote ..
> "Graham Dumpleton" <grahamd@dscpl.com.au> writes:
>
> per
> have
>
> This is interesting... how does it play with non-thread mpms?


Request cache code works in non-thread MPM as well, so just works,
nothing special to be done.

> part
>
> I specifically rejected that option myself.
>
> Programmers may or may not want to redirect logging through Apache. If
> mod_python used the system you describe there would either have to be:
>
> 1. config syntax to allow module 'logging' glue to be turned off
>
> 2. removal of the apache log handler in all code that didn't want it
>
> I don't like either of those.
>
> I can think of lots and lots of reasons why code using logging
> wouldn't want to log to Apache.


I attached the log handler to the "mod_python" logger. Thus you have
to select that logger explicitly for it to be redirected to Apache. If a user
wants other loggers to redirect to Apache, within a PythonImport module
they could grab the global log handler instance from where it is kept
and add it against other loggers as they see fit. They could still also
create their own instance of the Apache log handler as well, as the
request cache isn't within the instance anyway and so doesn't matter
if there is more than one.

Thus, use of logging to Apache is optional.

>
> I don't believe it is onerous to have to specifically attach the
> Apache log handling glue in the handler.


I would suggest though that rather than add such code to every single
handler, use a separate PythonHandler phase to do the work. That way
it is in one spot only at least.

>
> Another advantage of your system is that the logging config file
> syntax could be used to assign loggers (I think).


I'm not too knowledgeable on the logging module, perhaps you could
explain that one further. Would it simply be a case of somehow pointing
at mod_python.apache.ApacheLogHandler and it would create an instance
automatically??

Graham

Nic Ferrier

2005-10-24, 9:27 am

"Graham Dumpleton" <grahamd@dscpl.com.au> writes:

> Nic wrote:
>
> I attached the log handler to the "mod_python" logger. Thus you have
> to select that logger explicitly for it to be redirected to Apache. If a user
> wants other loggers to redirect to Apache, within a PythonImport module
> they could grab the global log handler instance from where it is kept
> and add it against other loggers as they see fit. They could still also
> create their own instance of the Apache log handler as well, as the
> request cache isn't within the instance anyway and so doesn't matter
> if there is more than one.
>
> Thus, use of logging to Apache is optional.


I don't believe this is as useful.

One major benefit of logging is that it is hierarchial. The reason
that I wanted the glue in the first place is that I have app code that
I want to interface to the web. The app code uses logging so it's
natural to try to make the logging go through Apache.

But I wouldn't want to have to change all my loggers to use the new
handler... that would be significant effort.

Your system *is* useful for more casual logging in the mod_python
context, say in an add-on handler framework.

But such frameworks could take the time to do their own logging
integration in whatever way makes sense for them.



>
> I would suggest though that rather than add such code to every single
> handler, use a separate PythonHandler phase to do the work. That way
> it is in one spot only at least.


Seems reasonable when you have lots and lots of entry points.


>
> I'm not too knowledgeable on the logging module, perhaps you could
> explain that one further. Would it simply be a case of somehow pointing
> at mod_python.apache.ApacheLogHandler and it would create an instance
> automatically??


Yes. You could say in a logging config file:

[loggers]
keys=mod_python,my_handler1,my_handler2,
my_handler3

[handlers]
keys=mod_python_logging_handler

[logger_my_handler1]
level=DEBUG
handlers=mod_python_logging_handler

I don't know how widespread logging config files are in the Python
world. They are *very* mandated in Java logging but Python logging
seems to me not to need them at all (I've not used one in anger yet).


Nic


Nick

2005-10-24, 9:27 am

Graham Dumpleton wrote:
> Hopefully everyone follows what I am talking about. I will try and get
> together a working example today of what I am talking about, but Nick,
> you may want to consider posting your code and how you are using it
> as it probably will not be too different.


Here's my sample code I was using. Very rough and unpolished, since I
ultimately decided not to use it. I haven't tried it in a while, but it
should more or less work. apache.py might contain the following code:

from logger import log_handler

Sample usage might look like the following (to steal your example from a
subsequent email):

from mod_python import apache
import logging

log = logging.getLogger("mod_python")
log.warning("importing handler")

def handler(req):
apache.log_handler.set_req(req) # <-- here's the extra code
log.warning("running handler")
req.content_type = 'text/plain'
req.send_http_header()
req.write('hello\n')
return apache.OK

Notice that if you *don't* call set_req, logging will still work, but
not according to any special ErrorLog settings in your apache config
other than the global setting. Also, since log_handler is available,
you can change it's default formatting options somehow as a mod_python
directive in your apache config, or whatever else you want to set.

Nick

Graham Dumpleton

2005-10-24, 9:27 am

Nic Ferrier wrote ..
> "Graham Dumpleton" <grahamd@dscpl.com.au> writes:
>
> If
> a user
>
> I don't believe this is as useful.


Hmmm, it puts it at about the same level of usefulness, if not slightly
more than your original proposal.

At its core, the only real difference is that the log handler uses a
separate global request cache rather than a distinct log handler
instance needing to be exist for each request.

Either way, to get the flexibility you want, user code still has to do
the association of a log handler to a specific logger at some point, eg.
preferably in a PythonImport module and only once. Adding a default
apache log handler against "mod_python" was to serve as an example
and possibly as a convenience when wanting to quickly put stuff together.

> One major benefit of logging is that it is hierarchial. The reason
> that I wanted the glue in the first place is that I have app code that
> I want to interface to the web. The app code uses logging so it's
> natural to try to make the logging go through Apache.
>
> But I wouldn't want to have to change all my loggers to use the new
> handler... that would be significant effort.


It may well be if you are already using this scheme whereby you have
separate log handlers for each request with uniquely named loggers for
each request/thread as well. I would say that that isn't an ideal design
to begin with. The code I suggested mean't request objects and threading
were handled transparently. This would simplify your code such that it
could use the same logger name all the time. You then only have to have
in one place the association of log handler to logger. The code would
be simpler to understand then.

> Your system *is* useful for more casual logging in the mod_python
> context, say in an add-on handler framework.
>
> But such frameworks could take the time to do their own logging
> integration in whatever way makes sense for them.


You are starting to make good points for why logging shouldn't be in
mod_python to begin with. That is, that a user is always probably
going to want to handle it in some special way, making it very hard
to provide a generic solution. :-)

Graham

Graham Dumpleton

2005-10-24, 9:27 am

Yes, effectively the same as what I was doing. As I highlighted in prior
email though about request cache implementations, not sure it would
work correctly if an internal redirect occurred and both original handler
and target of internal redirect had registered request object. One needs
to use a stack for self.local.req and push/pop the request object on to
it.

Your code would still work, but if anything was logged by the original
handler after the internal redirect had returned, the request object will
have been wiped out and it would not log through "req" but through
"apache.log_error()" instead.

Graham

Nick wrote ..
> Graham Dumpleton wrote:
>
> Here's my sample code I was using. Very rough and unpolished, since I
> ultimately decided not to use it. I haven't tried it in a while, but it
> should more or less work. apache.py might contain the following code:
>
> from logger import log_handler
>
> Sample usage might look like the following (to steal your example from
> a
> subsequent email):
>
> from mod_python import apache
> import logging
>
> log = logging.getLogger("mod_python")
> log.warning("importing handler")
>
> def handler(req):
> apache.log_handler.set_req(req) # <-- here's the extra code
> log.warning("running handler")
> req.content_type = 'text/plain'
> req.send_http_header()
> req.write('hello\n')
> return apache.OK
>
> Notice that if you *don't* call set_req, logging will still work, but
> not according to any special ErrorLog settings in your apache config
> other than the global setting. Also, since log_handler is available,
> you can change it's default formatting options somehow as a mod_python
> directive in your apache config, or whatever else you want to set.
>
> Nick


Nic Ferrier

2005-10-24, 9:27 am

"Graham Dumpleton" <grahamd@dscpl.com.au> writes:

> Either way, to get the flexibility you want, user code still has to do
> the association of a log handler to a specific logger at some point, eg.
> preferably in a PythonImport module and only once. Adding a default
> apache log handler against "mod_python" was to serve as an example
> and possibly as a convenience when wanting to quickly put stuff
> together.


There's a logging way to do it and a mod_python way to do it.

I don't care really. I find my system preferable for the reasons I
stated before (you're PythonImport module is really the syntax I was
talking about earlier).

But if it gets it into the distrib that's fine.


>
> It may well be if you are already using this scheme whereby you have
> separate log handlers for each request with uniquely named loggers for
> each request/thread as well. I would say that that isn't an ideal design
> to begin with. The code I suggested mean't request objects and threading
> were handled transparently. This would simplify your code such that it
> could use the same logger name all the time. You then only have to have
> in one place the association of log handler to logger. The code would
> be simpler to understand then.


No, no, no. I don't want to use the same logger all the time. logging
is *supposed* to use many loggers.

There is no programming constraint that requires unique logger names
for requests (I realise I may have implied that - it is not so). But
it is useful when you want to narrow a stream of logging down to a
particular request.

In even a moderately sized system using loggers each method would have
it's own logger.

The utility of mod_python/apache logging glue is that it allows you to
add the handler to the base logger and get all your code logging
to the right place without changing it.

So you have some nice code that has unit tests and runs nicely outside
of mod_python and then you have some handler code that maps it into
mod_python. And the logging in all of that code just works magically
because the mod_python/handler maps Python logging to apache logging.


>
> You are starting to make good points for why logging shouldn't be in
> mod_python to begin with. That is, that a user is always probably
> going to want to handle it in some special way, making it very hard
> to provide a generic solution. :-)


I didn't say that.

I said the add on frameworks would probably want to do it themselves.

Your system will cause people not using add on frameworks to either
use the default provided logger all the time or to add a PythonImport
to map your handler onto the loggers.


But I don't really care - if your code is can get into mod_python so
their is some standard glue for mapping logging into apache then
that's great.


Nic

Nick

2005-10-24, 9:27 am

Graham Dumpleton wrote:
> Yes, effectively the same as what I was doing. As I highlighted in prior
> email though about request cache implementations, not sure it would
> work correctly if an internal redirect occurred and both original handler
> and target of internal redirect had registered request object. One needs
> to use a stack for self.local.req and push/pop the request object on to
> it.


Hm, very well. I never really considered the case of using the internal
redirect. I'm an "old school" mod_python user, so I'm not up on all the
new features apache2 brings to the table. Reading the docs, I would
suppose you could make use of req.prev somehow in these cases rather
than manually keeping a separate stack? E.g. in my free_req function,
do "self.local.req = self.local.req.prev" (assuming if there hasn't been
an internal_redirect, req.prev is None).

> Your code would still work, but if anything was logged by the original
> handler after the internal redirect had returned, the request object will
> have been wiped out and it would not log through "req" but through
> "apache.log_error()" instead.


Right, that's the intention: provide a reasonable fallback.
[vbcol=seagreen]
>
> Graham
>
> Nick wrote ..
>

Graham Dumpleton

2005-10-24, 9:27 am

Nick wrote ..
> Graham Dumpleton wrote:
> to
>
> Hm, very well. I never really considered the case of using the internal
> redirect. I'm an "old school" mod_python user, so I'm not up on all the
> new features apache2 brings to the table. Reading the docs, I would
> suppose you could make use of req.prev somehow in these cases rather
> than manually keeping a separate stack? E.g. in my free_req function,
> do "self.local.req = self.local.req.prev" (assuming if there hasn't been
> an internal_redirect, req.prev is None).


Unfortunately you can't do that as all Python request objects in that
chain are created fresh for the handler which is the target of the
internal redirect. When the internal redirect returned, the cached
would then be actually different to the original. It would still return
the same underlying Apache data, but any extra stuff added to the
request object from Python code wouldn't be accessible.

Graham

Nick

2005-10-24, 9:27 am

Graham Dumpleton wrote:
> Unfortunately you can't do that as all Python request objects in that
> chain are created fresh for the handler which is the target of the
> internal redirect. When the internal redirect returned, the cached
> would then be actually different to the original. It would still return
> the same underlying Apache data, but any extra stuff added to the
> request object from Python code wouldn't be accessible.


The cleanup routine gets called at the end of each request, so I don't
think that's an issue that couldn't be resolved with the method I was
describing. Perhaps I was being too simplistic in my example to fully
explain what I was thinking, though.

But in any case, I think the problem could be solved much more simply by
changing the following code:

def set_req(self, req):
prev_req = self.local.req
self.local.req = req

def free_req():
self.local.req = prev_req
req.register_cleanup(free_req)

That should take care of restoring the previous "cached" request object
without explicitly creating a stack (i.e. relying on the Python call
stack to bind local variables in the closure).

Nick

Graham Dumpleton

2005-10-24, 9:27 am

Nick wrote ..
> Graham Dumpleton wrote:
>
> The cleanup routine gets called at the end of each request, so I don't
> think that's an issue that couldn't be resolved with the method I was
> describing. Perhaps I was being too simplistic in my example to fully
> explain what I was thinking, though.
>
> But in any case, I think the problem could be solved much more simply by
> changing the following code:
>
> def set_req(self, req):
> prev_req = self.local.req
> self.local.req = req
>
> def free_req():
> self.local.req = prev_req
> req.register_cleanup(free_req)
>
> That should take care of restoring the previous "cached" request object
> without explicitly creating a stack (i.e. relying on the Python call
> stack to bind local variables in the closure).


Yeah, that would work. Quite cute actually.

It is only recently that I realised that a nested function like that
could access stack variables of the enclosing function. Might look
at changing how I do things to use this method and eliminate
my use of the list as a stack.

Thanks.

Graham

Graham Dumpleton

2005-10-24, 9:27 am

Graham Dumpleton wrote ..
> It is only recently that I realised that a nested function like that
> could access stack variables of the enclosing function.


I should have added, "when the execution of the enclosing function has
already finished and the nested function is called at a later time". I'm
not that stupid that I didn't know the nested function could access data
in enclosing function when enclosing function hadn't returned yet. :-)

Anyway, I have attached an updated version of my log handler. This fixes
the issue with log levels that don't exactly map to any defined level.
Eliminates the explicit stack for storing request objects and in general
tries to make the module durable in the face of any module reloading
scheme for mod_python which exists now or which may exist in the future.

You can either use the default "mod_python" log it sets up, or create
explicit instances of ApacheLogHandler and add them against any log
within the hierarchy that you want.

Any feedback most welcome.

Graham


Nick

2005-10-24, 9:27 am

Graham Dumpleton wrote:
> Anyway, I have attached an updated version of my log handler. This fixes
> the issue with log levels that don't exactly map to any defined level.
> Eliminates the explicit stack for storing request objects and in general
> tries to make the module durable in the face of any module reloading
> scheme for mod_python which exists now or which may exist in the future.
>
> You can either use the default "mod_python" log it sets up, or create
> explicit instances of ApacheLogHandler and add them against any log
> within the hierarchy that you want.
>
> Any feedback most welcome.


Seems kind of overly complicated to me. If this was something to be
integrated into the mod_python core, I think it should probably be
implemented at a lower level, perhaps even set up by the dispatcher before
the first handler is dispatched and cleaned up at the end automatically.
That is, only if you have enabled some sort of mod_python directive in the
apache.conf file. As it is now it still seems sort of hack-ish.

Additionally, if this is to fully interface with apache's log_error
function, then the other severities should be added as logging levels, which
is possible with logger.

Nick

Jim Gallacher

2005-10-24, 9:27 am

Graham Dumpleton wrote:
> Graham Dumpleton wrote ..
>
>
>
> I should have added, "when the execution of the enclosing function has
> already finished and the nested function is called at a later time". I'm
> not that stupid that I didn't know the nested function could access data
> in enclosing function when enclosing function hadn't returned yet. :-)
>
> Anyway, I have attached an updated version of my log handler. This fixes
> the issue with log levels that don't exactly map to any defined level.
> Eliminates the explicit stack for storing request objects and in general
> tries to make the module durable in the face of any module reloading
> scheme for mod_python which exists now or which may exist in the future.
>
> You can either use the default "mod_python" log it sets up, or create
> explicit instances of ApacheLogHandler and add them against any log
> within the hierarchy that you want.
>
> Any feedback most welcome.
>


I've taken a look at the code and I'll give it whirl sometime today.

I'm wondering where the PythonLogHandler directive might fit into the
scheme of things. One problem of course is that any PythonLogHandler
gets called *after* any PythonHandlers.

Jim

Nick

2005-10-24, 9:27 am

Jim Gallacher wrote:
> I'm wondering where the PythonLogHandler directive might fit into the
> scheme of things. One problem of course is that any PythonLogHandler
> gets called *after* any PythonHandlers.


I believe the PythonLogHandler is used to intercept and handle logging in
apache itself. For example, you could write log information to a database
in a PythonLogHandler rather than (or in addition to) AccessLog and ErrorLog
files. But I'm going by what the mod_perl equivalent (which I've used)
does; I've never actually used a PythonLogHandler.

Not sure that it has any bearing on the logging handler as discussed, but I
could see someone's loghandler utilizing the logging module.

Now my head is spinning

Nick

Jim Gallacher

2005-10-24, 9:27 am

Graham Dumpleton wrote:
> Graham Dumpleton wrote ..
>
>
>
> I should have added, "when the execution of the enclosing function has
> already finished and the nested function is called at a later time". I'm
> not that stupid that I didn't know the nested function could access data
> in enclosing function when enclosing function hadn't returned yet. :-)
>
> Anyway, I have attached an updated version of my log handler. This fixes
> the issue with log levels that don't exactly map to any defined level.
> Eliminates the explicit stack for storing request objects and in general
> tries to make the module durable in the face of any module reloading
> scheme for mod_python which exists now or which may exist in the future.
>
> You can either use the default "mod_python" log it sets up, or create
> explicit instances of ApacheLogHandler and add them against any log
> within the hierarchy that you want.
>
> Any feedback most welcome.


The quick and dirty test went well except when I tried to change the log
level. Using setLevel(logging.DEBUG) had which had no effect. Then I
remembered the apache LogLevel directive. I had "LogLevel warn" in my
virtual host config, so log.info("some message") was not making it into
the error log. The LogLevel directive is only available in the server
config or virtual host context. Trying to configure logging in a
..htaccess file will be a bit of a problem for users. This detail would
need to be addressed in the documentation.

Using the following code also gives some interesting results:

from mod_python import apache
from mod_python.apache_log_handler import ApacheLogHandler
import logging

def handler(req):
log = logging.getLogger()
hdlr = ApacheLogHander()
log.addHandler(hdlr)
log.warning("running handler")
req.content_type = 'text/plain'
req.write('hello\n')
return apache.OK

Each request will result in n + 1 log messages, where n is the total
number of requests. Kinda cool but not really what people will want.
This should also be highlighted in any documentation.

Regards,
Jim

Jim Gallacher

2005-10-24, 9:27 am

Nick wrote:
> Jim Gallacher wrote:
>
>
>
> I believe the PythonLogHandler is used to intercept and handle logging
> in apache itself. For example, you could write log information to a
> database in a PythonLogHandler rather than (or in addition to) AccessLog
> and ErrorLog files. But I'm going by what the mod_perl equivalent
> (which I've used) does; I've never actually used a PythonLogHandler.
>
> Not sure that it has any bearing on the logging handler as discussed,
> but I could see someone