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'
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.