How to change date format for Django logging?

Question

The comments in the answer here say that you should be able to customize the date format for logging in Django:

Note that if you're using the dictConfig method of configuring logging (e.g. if you're using Django), you can set this using the 'datefmt' dict key for a formatter. See: Django Logging Configuration , logging module: Dictionary Schema Details

However, it does not work:

# settings.py
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'django.server': { # duplicate of default for django.server
            '()': 'django.utils.log.ServerFormatter',
            'format': '[{server_time}] {message}',
            'style': '{',
            'datefmt' : '%Y-%m-%d %H:%M:%S'
            }
}

This does not work either:

# settings.py
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'default': {
            'datefmt' : '%Y-%m-%d %H:%M:%S'
            },
}

In both cases, I still get the default logging date format:

[13/Mar/2019 21:53:05] "GET / HTTP/1.1" 200 16808

Note that in the source code, the datefmt should have been passed on and used, but it appears that this is not the case:

https://github.com/django/django/blob/782d85b6dfa191e67c0f1d572641d8236c79174c/django/utils/log.py#L190

Using Python 3.6 and Django 2.1

---

Update:

When I include this in my settings.py as described:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'django.server': {
            '()': 'django.utils.log.ServerFormatter',
            'format': '[{server_time}] {message}',
            'datefmt' : '%Y-%m-%d %H:%M:%S',
            'style': '{',
        }
}

And then edit the file conda//lib/python3.6/site-packages/django/utils/log.py like this:

class ServerFormatter(logging.Formatter):
    def __init__(self, *args, **kwargs):
        self.style = color_style()
        super().__init__(*args, **kwargs)
        print("self.datefmt", self.datefmt)

I get messages in my console that look like this, indicating that I actually am propagating the datefmt correctly:

$ python manage.py runserver
self.datefmt %Y-%m-%d %H:%M:%S
self.datefmt %Y-%m-%d %H:%M:%S
Performing system checks...

System check identified no issues (0 silenced).
March 13, 2019 - 23:43:50
Django version 2.1.2, using settings 'webapp.settings'
Starting development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.
[13/Mar/2019 23:45:14] "GET / HTTP/1.1" 200 16808

Maybe the error has to do with this line in django/utils/log.py?

if self.uses_server_time() and not hasattr(record, 'server_time'):
            record.server_time = self.formatTime(record, self.datefmt)

^ No matter what I do, it appears that this check never gets tripped, because not hasattr(record, 'server_time') always evaluates to False, because record already has server_time by default, and it appears to come from this section of Django code in django/core/servers/basehttp.py:

class WSGIRequestHandler(simple_server.WSGIRequestHandler):
...
...
    def log_message(self, format, *args):
        extra = {
            'request': self.request,
            'server_time': self.log_date_time_string(),
        }

Where simple_server.WSGIRequestHandler.log_date_time_string() is coming from the wsgiref package. However, that package does not contain any reference to the function log_date_time_string(), it appears to be coming directly from the Python builtin http library (conda//lib/python3.6/http/server.py):

def log_date_time_string(self):
    """Return the current time formatted for logging."""
    now = time.time()
    year, month, day, hh, mm, ss, x, y, z = time.localtime(now)
    s = "%02d/%3s/%04d %02d:%02d:%02d" % (
            day, self.monthname[month], year, hh, mm, ss)
    return s

^ The date format here is hard-coded into the library, does not appear to be changeable.

So... how is any of this supposed to work? Am I missing something? Is this some sort of bug in Django? Unless I am mistaken there is no way to override this datefmt based on this?

Answer 1

A solution is to use the attribute asctime instead of server_time, e.g.

           'format': '[{asctime}] {message}',`
           'datefmt' : '%Y-%m-%d',`

I think server_time is a modified attribute used by the logger 'django'. When I tried to format log messages for the logger 'root' with server_time, I get an error indicating that the attribute server_time is not recognized.

    raise ValueError('Formatting field not found in record: %s' % e)
ValueError: Formatting field not found in record: 'server_time'

I think server_time is a formatted string value generated from asctime and provided by django logger, and therefore it does not work try to modify it again with datefmt.

datefmt works fine to modify the attribute asctime

Answer 2

That was a good, detailed investigation. Make sure that your research includes the Django ticket tracker. The first hit on a search for site:code.djangoproject.com datefmt reveals that this is a known bug.

That ticket shows a possible workaround—use asctime instead of server_time.