Log all requests to file Django

Question

When I run the django development server (./manage.py runserver) all requested urls are conveniently logged into process stdout, with the precise time and the response code:

[09/Jun/2016 23:35:53] "GET /api/game/ HTTP/1.1" 404 3185
[09/Jun/2016 23:36:01] "GET /api/game/123/ HTTP/1.1" 404 1735

It is very handy because when analysing output you immediately see the request corresponding to your log messages, for example:

WARNING:2016-06-09 23:41:27,806:views:7449:140139847718656: No such object in the database: u'123'
[09/Jun/2016 23:41:27] "GET /api/game/123/ HTTP/1.1" 404 1735

I used to work with uwsgi+nginx, so I used 'console' logging handler for everything, and then started uwsgi like this:

exec uwsgi --master --die-on-term --logto /var/log/uwsgi.log

As a result I got all the necessary logging in /var/log/uwsgi.log, uwsgi's request records and my own logging messages.

Now I want to achieve the same result with Apache+mod WSGI+django. I want the only file to contain all requests and all the logs from my django app in one place.

I've tried to achieve this with Django logging configuration, but even when I redirect django.requests to the same file I get only my own messages in the logs, no requests at all. Here is the portion of the configuration:

'handlers': {
    'file_handler': {
        'level': DEBUG and 'DEBUG' or 'INFO',
        'class': 'logging.handlers.RotatingFileHandler',
        'filename': join(LOG_DIRECTORY, 'api_log.log'),
        'maxBytes': 1024 * 1024 * 5,  # 5 MB
        'backupCount': 15,
        'formatter': 'verbose',
    },
},
'loggers': {
    'api': {
        'handlers': ['file_handler'],
        'level': DEBUG and 'DEBUG' or 'INFO',
    },
    'django': {
        'handlers': ['file_handler'],
        'level': DEBUG and 'DEBUG' or 'INFO',
    },
    'django.request': {
        'handlers': ['file_handler'],
        'level': DEBUG and 'DEBUG' or 'INFO',
    },
    'django.db.backends': {
        'handlers': ['file_handler'],
        'level': DEBUG and 'INFO' or 'WARNING',
        'propagate': False,
    },
}

Is there a way to achieve nginx+uwsgi+django logging behavior with apache+WSGI+django? Or the only way is to keep apache access.log and my logs in separate files?

I guess in the first case it was development server who logged requests, and in the second case it was uwsgi process. Maybe there's a way to tell WSGIDaemonProcess to do the same?

Solution

For a standard Apache installation you are going against what is regarded as best practice by trying to mingle both access logs and error logs. Traditionally they have been left separate so that analysis could be done on access logs on server traffic.

That said, have you tried changing the ErrorLog and CustomLog directives in Apache to use the same file?

When I used mod_wsgi-express with the command:

mod_wsgi-express start-server --access-log --access-log-name application.log --error-log-name application.log

it is generating:

<IfDefine MOD_WSGI_ROTATE_LOGS>
ErrorLog "|/usr/sbin/rotatelogs \
    /tmp/mod_wsgi-localhost:8000:502/application.log.%Y-%m-%d-%H_%M_%S 5M"
</IfDefine>
<IfDefine !MOD_WSGI_ROTATE_LOGS>
ErrorLog "/tmp/mod_wsgi-localhost:8000:502/application.log"
</IfDefine>
LogLevel warn

<IfDefine MOD_WSGI_ACCESS_LOG>
<IfModule !log_config_module>
LoadModule log_config_module ${MOD_WSGI_MODULES_DIRECTORY}/mod_log_config.so
</IfModule>
LogFormat "%h %l %u %t \"%r\" %>s %b" common
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-agent}i\"" combined
LogFormat "undefined" custom
<IfDefine MOD_WSGI_ROTATE_LOGS>
CustomLog "|/usr/sbin/rotatelogs \
    /tmp/mod_wsgi-localhost:8000:502/application.log.%Y-%m-%d-%H_%M_%S 5M" common
</IfDefine>
<IfDefine !MOD_WSGI_ROTATE_LOGS>
CustomLog "/tmp/mod_wsgi-localhost:8000:502/application.log" common
</IfDefine>
</IfDefine>

with the resulting application.log being:

[Fri Jun 10 07:17:30.845264 2016] [mpm_prefork:notice] [pid 84334] AH00163: Apache/2.4.18 (Unix) mod_wsgi/4.5.2 Python/2.7.10 configured -- resuming normal operations
[Fri Jun 10 07:17:30.845518 2016] [core:notice] [pid 84334] AH00094: Command line: 'httpd (mod_wsgi-express)  -f /tmp/mod_wsgi-localhost:8000:502/httpd.conf -D MOD_WSGI_ACCESS_LOG -D FOREGROUND'
::1 - - [10/Jun/2016:07:17:36 +1000] "GET / HTTP/1.1" 200 709
::1 - - [10/Jun/2016:07:17:37 +1000] "GET / HTTP/1.1" 200 709
::1 - - [10/Jun/2016:07:17:37 +1000] "GET / HTTP/1.1" 200 709
::1 - - [10/Jun/2016:07:17:38 +1000] "GET / HTTP/1.1" 200 709
::1 - - [10/Jun/2016:07:17:38 +1000] "GET / HTTP/1.1" 200 709
[Fri Jun 10 07:17:39.784486 2016] [mpm_prefork:notice] [pid 84334] AH00169: caught SIGTERM, shutting down

So technically it should work for a standalone Apache installation with both error and access log going to the same file just by setting ErrorLog and CustomLog to the same file.

As for additional Django logging it may generate internally due to exceptions, you still would also need:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'INFO'),
        },
    },
}

This tells Django to notionally log to the terminal, which mod_wsgi will intercept and send to the Apache error log, which with the above will be the combined application log.

BTW, if wanting to run Apache/mod_wsgi in a container where logging needs to go to standard output, do not do it yourself. Use mod_wsgi-express as it is specifically designed for use in containers. In that case you would just use:

mod_wsgi-express start-server --access-log --log-to-terminal

if want to enable access logging (off by default as generally just noise for container deployments) and it will worry about sending both access and error logs to the terminal so Docker can capture it.

If need more information or assistance, use the mod_wsgi mailing list.