Natural Order Development

OK so this took more then a while to figure out. I had to go read the FAST CGI specification (http://www.fastcgi.com/devkit/doc/fcgi-spec.html), the lighttpd FastCGI Interface docs (http://trac.lighttpd.net/trac/wiki/Docs:ModFastCGI), the Django FastCGI docs (http://www.djangoproject.com/documentation/fastcgi/) and a number of other forum posts in a number of groups.

All this just to answer the question: How do I get my Python Django applications to print to the the lighttpd error logs when using Lighttpd + FastCGI?

At last I found the answer. At least partially...

The crux of this problem is that FastCGI is a multi-threaded and multiplexed communication protocol. Just calling print is not enough. The output streams need to be encoded and directed to the right channel and in a way that the FCGI service can untangle them to know where they should be routed.

This is a messy problem due to the complexity, the poor documentation, the incomplete state of the specifications and also the incomplete state of the FCGI supporting modules on both the server and client ends.

So here is the basic trick.

You can not do this from a settings file. The streams are not available UNTIL there is a call that causes the FCGI instance to initiate a request. The streams will be available via the request call. They might be set up in the environment (there are supposed to a couple of hooks for you to look for and then snag onto). I haven't finished getting all this figured out yet. But, I have succeeded in having a multi-threaded call to a single FCGI channel successfully process all the data into responses with resulting messages ending up in the expected logs.

Once you have the request it is not too difficult to do this. For example within the views of a Django application you can do this:

if 'wsgi.errors' in request.META:
    request.META['wsgi.errors'].writelines("An error message for the server's error logs.\n")
    request.META['wsgi.errors'].flush()

Now that I know where to find these channels and I know how to use them correctly (using them correctly is the key). I can experiment with a few other tricks I know to see if I can make this as easy as:

if isFCGI():
    dup2StdStreams()

print "This should go to the access log."
print >>sys.stderr "This should go to the error log."

If not then I can at least hook into the python logging and set up the logging to go to the server's access and error logs.

Well it has been a cruddy day. I have been trying to figure out a problem with the fcgi implementation. Seem to have been running circles around myself here.

There is a bug in the Django source specifically in django/core/servers/fastcgi.py that was ignores the output settings unless the process is being daemonized. So I added the else clause below has fixed it so I am now getting stdout and stderr messages.

    if daemonize:
        from django.utils.daemonize import become_daemon
        become_daemon(our_home_dir=options["workdir"], **daemon_kwargs)
    else:
        if options['outlog']:
            so = open(options['outlog'], 'a+', 0)
            os.dup2(so.fileno(), sys.stdout.fileno())
        if options['errlog']:
            se = open(err_log, 'a+', 0)
            os.dup2(se.fileno(), sys.stderr.fileno())

Except that that breaks the fcgi interactions. With that change I am not able to get responses through the auto-generated named pipes. It seems I have to hand it the bind name for the pipe. But if I do that and daemonize it then lightttpd looses control and if I stop the services the python processes persist.

On the other hand I am getting a lot of code crawling experience on the python classes. Which leads me to another observation.

Why are so many open source developers so lazy about documentation. If you are going to publish something you dang well had better provide solid design docs, API references and user docs. But, no fcgi is not well documented, lighttpd is not well documented, django is not well documented and Sphene Community Tools are not well documented. Which means I have to spend hours of code crawling to figure anything out.

And it isn't just open source developers I have the same problems at work too. Major enterprise systems with cruddy docs and lots of black magic development lead to a nightmare of work. I have heard some people laugh at this and say "well that is called job security." It isn't job security it is crappy development and laziness. My customers have plenty of additional work they want me to do. I am sure they could give me a list 60 years long.

<SIGH> well back to code crawling.

Oh what a quagmire of crud to walk through. All of the Django docs on FCGI and lighttpd are pretty sparse and the examples are not what I would recommend for a production service. So first step was to improve the FCGI tie in for Django. This turned out better then I thought. I had to do a lot of guessing and testing. But now I have it set up so that when the lighttpd service is started and stopped the FCGI processes are also started and stopped. In other words the web service application actually controls its own subprocesses including the FCGI linking to python for the Django service.

I'll have to create a wiki pages on how I configured this place. But to save you time if you want to see my script here it is:

-- BEG start-fcgi.sh --

#!/usr/bin/env bash

NOW=`date +%Y-%m-%d_%T`
MY_LOG_DIR=/tmp
[ -n "${OUT_LOG}" ] && MY_LOG_DIR=${OUT_LOG%/*}
[ -n "${DJANGO_LOG_DIR}" ] && MY_LOG_DIR=${DJANGO_LOG_DIR}
[ ! -d $MY_LOG_DIR ] && mkdir -p  $MY_LOG_DIR
[ ! -d $MY_LOG_DIR ] && echo "$0 ERROR log dir $MY_LOG_DIR is not a directory" >&2 && exit -1
MY_LOG=${MY_LOG_DIR}/start_fcgi_${NOW}_$$.out
rm -rf $MY_LOG
echo "$0 process $$ started log file = $MY_LOG"
echo "$0 process $$ started" >> ${MY_LOG}
MY_DIR=${0%/*}
cd $MY_DIR
echo "command line: $0 $@" > ${MY_LOG}
echo "----- BEG ENV -----" >> ${MY_LOG}
env >> ${MY_LOG}
echo "----- END ENV -----" >> ${MY_LOG}
PIDFILE="pidfile=${MY_LOG_DIR}/django_fcgi_$$.pid"
[ -n "${DJANGO_PID}" ] && PIDFILE="pidfile=${DJANGO_PID}"

# if socket is not specified the fcgi process handling will negotiate the correct
# socket file via the fcgi API so best to NOT specify it
SOCKET=""
[ -n "${DJANGO_SOCKET}" ] && SOCKET="socket=${DJANGO_SOCKET}"
METHOD="method=prefork"
[ -n "${DJANGO_METHOD}" ] && METHOD="method=${DJANGO_METHOD}"

# stdout and stderr will go to the http server logs if not otherwise specified
OUTLOG=""
[ -n "${OUT_LOG}" ] && OUTLOG="outlog=${OUT_LOG}"
ERRLOG=""
[ -n "${ERROR_LOG}" ] && ERRLOG="errlog=${ERROR_LOG}"

CMD="./manage.py runfcgi $METHOD $SOCKET $PIDFILE $OUTLOG $ERRLOG"

echo "executing : exec ${CMD}" >> ${MY_LOG}

exec ${CMD}

-- END start-fcgi.sh --


You will note that this is controlled via the lighttpd.conf file. Here is the relevant section of mine:

-- BEG lighttpd.conf subsection --

## Special fastcgi handling for each domain under django python
# If the hostname is '*.nodsw.com' or 'nodsw.com' ...
$HTTP["host"] =~ "(^|\.)nodsw.com" {
    fastcgi.server += (
        "/mysite.fcgi" => (
            "main" => (
                "socket" => "/tmp/nodsw.socket", # This will get auto-incremented by fcgi
                "check-local" => "disable",
                "bin-path" => "/django/nodsw.com/start_fcgi.sh",
                "bin-environment" => (
                    "DJANGO_LOG_DIR"         => "/django/logs",
                    #"ERROR_LOG"              => "/django/logs/nodsw.django_error.log",
                    #"OUT_LOG"                => "/django/logs/nodsw.django_out.log",
                    #"DJANGO_PID"             => "/django/logs/nodws.django.pid"
                    #"DJANGO_SOCKET"          => "/tmp/nodsw.socket", # don't use this unless you are sure
                    #"PYTHONPATH" => "/django/greydragon/project"
                )
            )
        )
    )
    alias.url = (
        "/media/" => "/django/nodsw.com/media/",
    )

    url.rewrite-once = (
        "^(/media.*)$" => "$1",
        "^/favicon\.ico$" => "/media/favicon.ico",
        "^(/.*)$" => "/mysite.fcgi$1",
    )
}

-- END lighttpd.conf subsection --