multiple log lines

[Jared Greenwald]

I'm in the midst of converting an application from mod_python to mod_wsgi and I'm having an issue with our logging functionality.  We have a centralized init function for logging that runs getLogger and sets up the file handler object and things like that.  There's also a centralized log function that also calls getLogger to write out to the log.  We also have two separate namedvirtualhost configs in our global apache config - one for localhost for admin type operations and one for the external interface for client/customer operations (I have an environment variable in each VH config stanza that points to an environment-specific config file that identifies the log file for that environment among other things).  I'm seeing the application logging to the correct log file for each environment, but at times I'm getting duplicate log entries (I've gotten it up to x8).  I know it's not actually duplicating the work as I have a couple places where I use mkstemp and I'm seeing the same temp file name in each duplicated log output.  So, I'm guessing there's something to do with how the centralized convenience functions are setting up and calling the logging library functions.  Is there any best practice guide on how to do logging properly under mod_wsgi?  I should also point out that this setup works under mod_python/python2.4 (vs mod_wsig/python2.7).

Thanks,

Jared

[Graham Dumpleton]

Are you using embedded mode or daemon mode of mod_wsgi?

It sounds like you are using embedded mode of mod_wsgi and modifying or updating the time stamp on the WSGI script file for the application, causing it to be reloaded in the context of the same process. If that WSGI script is trigger initialisation of logging, then it will be triggered it a subsequent time for the process.

Ideally you should be using daemon mode as it is the recommended configuration. Otherwise you would need to code up the WSGI script file to not perform process initialisation if it has already been done.

Check out how reloading works in:

https://modwsgi.readthedocs.io/en/develop/user-guides/reloading-source-code.html

Also:

https://modwsgi.readthedocs.io/en/develop/user-guides/checking-your-installation.html#embedded-or-daemon-mode

Graham

--
You received this message because you are subscribed to the Google Groups "modwsgi" group.
To unsubscribe from this group and stop receiving emails from it, send an email to modwsgi+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/modwsgi/cdedca07-b5fb-4e58-a16f-661c2a5a2251%40googlegroups.com.

[Jared Greenwald]

So, configuring daemon mode is just a matter of setting something like the following in the VH config?

    WSGIDaemonProcess example.com processes=2 threads=15 display-name=%{GROUP}

    WSGIProcessGroup example.com

Graham

To unsubscribe from this group and stop receiving emails from it, send an email to mod...@googlegroups.com.

[Graham Dumpleton]

In the simplest case yes.

You may though want to watch the talk:

https://www.youtube.com/watch?v=CPz0s1CQsTE

for other tips on configuring daemon mode.

Graham

To unsubscribe from this group and stop receiving emails from it, send an email to modwsgi+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/modwsgi/69820b0c-6644-4d69-8505-4607c3cf6d8f%40googlegroups.com.

[Jared Greenwald]

Ok, so from the video there was a table of "sane"/recommended values to set for these apache directives.  Is there an example of this other than just that table?  Also, the values listed in the table - are those sane examples for a production system?  For my situation where I have a couple different environments via different NamedVirtualHost configs listening on different ports - would I separate those with different process groups?  Should there be some correlation between the number of apache threads and the number of mod_wsgi threads?

Graham

To view this discussion on the web visit https://groups.google.com/d/msgid/modwsgi/69820b0c-6644-4d69-8505-4607c3cf6d8f%40googlegroups.com.

[Graham Dumpleton]

On 12 Sep 2019, at 5:30 am, Jared Greenwald <greenwa...@gmail.com> wrote:

Ok, so from the video there was a table of "sane"/recommended values to set for these apache directives.  Is there an example of this other than just that table?

As mentioned in the talk, they come from what mod_wsgi-express uses. So you could pip install mod_wsgi and run mod_wsgi-express, then see what it generates in its config. It also will make it easier to play with the values as can change using command line options.

Also, the values listed in the table - are those sane examples for a production system?

They are more sane starting defaults than the defaults you would get if installing mod_wsgi yourself. The mod_wsgi-express variant uses them as defaults as they have found to be better than builtin defaults to mod_wsgi. It isn't possible to go back and change the builtin defaults cause that could upset existing users.

For my situation where I have a couple different environments via different NamedVirtualHost configs listening on different ports - would I separate those with different process groups?

Yes you should tailor them if necessary. See:

http://blog.dscpl.com.au/2014/02/vertically-partitioning-python-web.html

Should there be some correlation between the number of apache threads and the number of mod_wsgi threads?

The Apache process/thread capacity must at least be larger than what daemon process group requires, with extra capacity to handle static file handling at the same time, as some request queue buffering if daemon process reach capacity. When have multiple daemon process groups, don't just make Apache capacity sum total of daemon processes as that is probably a waste. You need to understand what load is like on daemon process groups to come to a reasonable middle ground.

Another talk worth watching:

https://www.youtube.com/watch?v=k6Erh7oHvns

To unsubscribe from this group and stop receiving emails from it, send an email to modwsgi+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/modwsgi/eec01b43-b886-4b80-98ac-95a1191b3d7c%40googlegroups.com.

[Jared Greenwald]

Thanks much for all this info, it's a lot to process but at least I have some stuff to research.  I did convert my config over to mod_wsgi daemon but it doesn't seem to have had any affect on my log output duplication.  My application is an XMLRPC server and when I call the client code with any sort of rapid succession it starts piling up the duplication.  I'm not sure it has anything to do with embedded vs daemon, but maybe how I'm using the python logging module?  That was partly my original question was if there was some sort of best practice for setting up the python logging.  I'm guessing that the handler is being processed multiple times for some reason.  I'm sure it's probably something simple that I'm missing, but this is code that was working fine under apache2.2/mod_python.  Any pointers you can provide would be greatly appreciated.

To view this discussion on the web visit https://groups.google.com/d/msgid/modwsgi/eec01b43-b886-4b80-98ac-95a1191b3d7c%40googlegroups.com.

[Graham Dumpleton]

All I can add is that anything sent to stdout/stderr will be sent to the Apache error log. So if you have set up a handler for logging module explicitly to send to console log, but somehow had it was defaulting to sending to stdout/stderr anyway, then could get duplicates.

What does your logging module config look like? What function are you calling to initialise the logging module and where?

To unsubscribe from this group and stop receiving emails from it, send an email to modwsgi+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/modwsgi/efa03f84-b88a-4938-9e28-95e46f923266%40googlegroups.com.

[Jared Greenwald]

I have two basic functions setup in a centralized log module in my project.

First function is called from the main application handler which is supposed to handle the setup of the logging config.  It essentially looks like the following:

def logconfig(loglevel, file):
    logger=logging.getLogger()
    handler=logging.handlers.TimedRotatingFileHandler(file,when='D',interval=1,backupCount=7)
    formatter = logging.Formatter('%(asctime)s.%(msecs)03d %(process)s L%(levelno)s %(message)s','%y%m%d-%H%M%S')

    handler.setFormatter(formatter)

    logger.addHandler(handler)

    logger.setLevel(level)

    logger.info("Logging initialized.")

Second, we have a convenience function for actually sending the log message to the log:

def log(message, level):

    logger = logging.getLogger()

    if level <= 10:

        file, line, func, txt = traceback.extract_stack(None, 2)[0]

        trace = '(File: %s, Method: %s(), Line: %s) ' % (file, func, line)

        message = trace + message

    logger.log(level, message)

My initial thought was that it had something to do with the fact that there is no name being passed to the getLogger function so there might be some confusion there but I played around with that a bit and wasn't able to get anywhere.  I'm not sure why it was originally done this way, but the other thought I had was that the logger object being setup in the init function should be a global and the log convenience function could just reference.  I haven't really been able to find a good example of the "right way" this should be done..

To unsubscribe from this group and stop receiving emails from it, send an email to mod...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/modwsgi/efa03f84-b88a-4938-9e28-95e46f923266%40googlegroups.com.

[Jared Greenwald]

Just to complete the thread on this.  It seems that the mod_wsgi threads are passing through this code on every new call to the server, so I just added a check that a previous handler had been allocated to the logger after doing the getLogger call and if the handler was already allocated, I just don't do any of the handler/formatter allocation.  That seems to have been enough to eliminate the duplicate log entries.