pythondjangodjango-logging

Django Logging Filter with KeyError


I have trouble with the Django logging and setting the custom filter.

This is my current settings:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'filters': {
        'user_filter': {
            '()': 'myapp.user_logging_filter.UserFilter',
        }
    },
    'formatters' : {
        'standard': {
            'format': '%(asctime)s [%(levelname)s] %(name)s %(current_user)s %(message)s'
        },
    },
    'handlers': {
        'default': {
            'level': 'DEBUG',
            'filters': ['user_filter'],
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'logs/debug.log',
            'maxBytes': 1024*1024*10,  # 10 MB
            'backupCount': 5,
            'formatter': 'standard',
        },
        'django': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'logs/django.log',
            'maxBytes': 1024*1024*10,  # 10 MB
            'backupCount': 5,
            'formatter': 'standard',
        },
    },
    'loggers': {

        'my': {
            'handlers': ['default'],
            'level': 'DEBUG',
            'propagate': True
        },
        'django': {
            'handlers': ['django'],
            'level': 'DEBUG',
            'propagate': True
        },
    }
}

and the filter class is currently:

import logging

class UserFilter(logging.Filter):

    def filter(self, record):
        print('INSIDE')
        record.current_user = 'Marko'
        return True

I get the error stack:

--- Logging error ---
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/logging/handlers.py", line 71, in emit
    if self.shouldRollover(record):
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/logging/handlers.py", line 187, in shouldRollover
    msg = "%s\n" % self.format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/logging/__init__.py", line 839, in format
    return fmt.format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/logging/__init__.py", line 579, in format
    s = self.formatMessage(record)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/logging/__init__.py", line 548, in formatMessage
    return self._style.format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/logging/__init__.py", line 391, in format
    return self._fmt % record.__dict__
KeyError: 'current_user'
Call stack:
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/utils/autoreload.py", line 225, in wrapper
    fn(*args, **kwargs)
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/core/management/commands/runserver.py", line 120, in inner_run
    self.check_migrations()
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/core/management/base.py", line 442, in check_migrations
    executor = MigrationExecutor(connections[DEFAULT_DB_ALIAS])
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/migrations/executor.py", line 18, in __init__
    self.loader = MigrationLoader(self.connection)
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/migrations/loader.py", line 49, in __init__
    self.build_graph()
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/migrations/loader.py", line 212, in build_graph
    self.applied_migrations = recorder.applied_migrations()
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/migrations/recorder.py", line 62, in applied_migrations
    return {tuple(x) for x in self.migration_qs.values_list('app', 'name')}
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/models/query.py", line 268, in __iter__
    self._fetch_all()
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/models/query.py", line 1186, in _fetch_all
    self._result_cache = list(self._iterable_class(self))
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/models/query.py", line 138, in __iter__
    return compiler.results_iter(tuple_expected=True, chunked_fetch=self.chunked_fetch, chunk_size=self.chunk_size)
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1017, in results_iter
    results = self.execute_sql(MULTI, chunked_fetch=chunked_fetch, chunk_size=chunk_size)
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1065, in execute_sql
    cursor.execute(sql, params)
  File "/Users/zadravecm/Work/Razvoj/Filc/Plansphere/env/lib/python3.6/site-packages/django/db/backends/utils.py", line 111, in execute
    extra={'duration': duration, 'sql': sql, 'params': params}
Message: '(%.3f) %s; args=%s'

Solution

  • I can't find any documentation about the issue, but I have encountered it myself as well.

    The solution is to not use underscores in your LogRecord Attribute names. In other words, change your variable from current_user to currentUser (in both your formatter and your filter) and it will work.