Not able to log with: KeyError: 'cid' ... Arguments: ()
izmailoff opened this issue · 3 comments
Hi, I might have come across a bug, please help me to validate this issue.
Environment:
Python 3.6
django-cid==2.0
django==2.2.8
Apache with mod_wsgi
I followed installation and configuration docs step by step. Getting an error when trying to log with CID:
--- Logging error ---
Traceback (most recent call last):
File "/usr/lib/python3.6/logging/__init__.py", line 994, in emit
msg = self.format(record)
File "/usr/lib/python3.6/logging/__init__.py", line 840, in format
return fmt.format(record)
File "/usr/lib/python3.6/logging/__init__.py", line 580, in format
s = self.formatMessage(record)
File "/usr/lib/python3.6/logging/__init__.py", line 549, in formatMessage
return self._style.format(record)
File "/usr/lib/python3.6/logging/__init__.py", line 391, in format
return self._fmt % record.__dict__
KeyError: 'cid'
Call stack:
File "...mysite/lib/python3.6/site-packages/django/core/handlers/wsgi.py", line 141, in __call__
response = self.get_response(request)
File "...mysite/lib/python3.6/site-packages/django/core/handlers/base.py", line 75, in get_response
response = self._middleware_chain(request)
File "...mysite/lib/python3.6/site-packages/django/core/handlers/exception.py", line 34, in inner
response = get_response(request)
File "...mysite/lib/python3.6/site-packages/cid/middleware.py", line 38, in __call__
response = self.get_response(request)
File "...mysite/lib/python3.6/site-packages/django/core/handlers/exception.py", line 34, in inner
response = get_response(request)
File "...mysite/lib/python3.6/site-packages/django/core/handlers/base.py", line 113, in _get_response
response = wrapped_callback(request, *callback_args, **callback_kwargs)
File "...mysite/lib/python3.6/site-packages/django/utils/decorators.py", line 142, in _wrapped_view
response = view_func(request, *args, **kwargs)
File "...mysite/myapis/some_apis.py", line 14, in do_something
log.info(f'META!!!!: {request.META}.')
Somehow CID is not able to find the header which is set by Apache. To troubleshoot I print headers from a django view in 2 ways:
-
log.info(f'HEADERS!!!!: {request.headers}.')
gives:'X-Correlation-Id': 'WGZkYUYxZXRGc3h0NGtmRldJSlRzUUFBQ UFN'
-
log.info(f'META!!!!: {request.META}.')
gives:'HTTP_X_CORRELATION_ID': 'WGZkYUYxZXRGc3h0NGtmRldJSlRzUUFBQUFN'
So the header is clearly present in the request. I tried both settings:
CID_HEADER = 'X-Correlation-Id'
or
CID_HEADER = 'HTTP_X_CORRELATION_ID'
and got the same error.
The rest of the Django settings is the same as in instructions:
'formatters': {
'default': {
'format': '[cid: %(cid)s] - %(asctime)s - %(name)s - %(levelname)s - %(threadName)s - %(message)s',
},
...
'handlers': {
'console': {
'class': 'logging.StreamHandler',
'formatter': 'default',
},
...
'filters': {
'correlation': {
'()': 'cid.log.CidContextFilter'
},
},
...
'mysite': {
'level': LOGLEVEL,
'handlers': ['console'],
'filters': ['correlation'],
'propagate': True,
},
Thanks,
Alex
Hello.
I am afraid I cannot reproduce this issue. I tried by tweaking the sandbox project included in django-cid.
A few ideas:
-
double check that your view is really using the
mysite
logger that you defined in your settings. For example, try to tweak the log level (in your view or in the settings) to make sure that the log messages are shown (or not shown) accordingly; -
double check your settings, perhaps by looking at the differences between your settings and the settings of the sandbox project. I know it can be tedious on a real, big project.
Hi @dbaty , sorry for the late reply. I suspect Django is not configuring logging correctly in multithreaded application. I didn't get around to debug it properly yet, but I'm planning to do it shortly. Please keep this issue open for now so we can comment on it.
Apologies, not able to troubleshoot this at the moment. Will close the ticket. If I manage to get clear details I'll reopen if needed. Thanks!