------------------------------------------------------------------------------ To reply, visit https://hellosplat.com/s/beanbag/tickets/4523/ ------------------------------------------------------------------------------
New ticket #4523 by kyz For Beanbag, Inc. > Review Board Status: New Tags: Priority:Medium, Type:Defect File attachments: * fix-logging-args.patch <https://hellosplat.com/s/beanbag/attachments/1218/> ------------------------------------------------------------------------------ ReviewBoard 2.5.8 and Djblets 0.9.5 call several logging methods with unexpected keyword argument 'request' ============================================================================== # What version are you running? ReviewBoard 2.5.8 # What's the URL of the page containing the problem? https://MYSERVER/reviews/r/1465/diff/1/fragment/24145/?index=0&1486735796&api_format=json (this is loaded by the review request's diff page) # What steps will reproduce the problem? 1. Load a diff page for a diff which doesn't cleanly apply. # What is the expected output? What do you see instead? Expected: diff fragment should have a warning message like "The patch to '%(filename)s' didn't apply cleanly. The temporary files have been left in ..." Actual: Django stack trace: Traceback: File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/core/handlers/base.py" in get_response 118. response = middleware_method(request, e) File "/usr/lib/python2.6/site-packages/Djblets-0.9.5-py2.6.egg/djblets/log/middleware.py" in process_exception 180. request=request) Exception Type: TypeError at /reviews/r/1465/diff/1/fragment/24145/ Exception Value: exception() got an unexpected keyword argument 'request' # What operating system are you using? What browser? ReviewBoard is hosted on RHEL 6, running Python 2.6.6 # Please provide any additional information below. ReviewBoard and Djblets use Python logging module, several methods of which don't take arbitrary keyword parameters, but only take one called 'extra'. Having just tested, in Python 2.6.6, Python 2.7.12 and Python 3.5.2: * logging.debug() and logging.log() accept any keyword parameters * logging.warning(), logging.exception(), logging.error() don't accept arbitrary keyword parameters, they require extra parameters to be in a dictionary parameter called "extra" Here, middleware.py fails because it calls `logging.exception("blah", ..., request=request)`. Instead, it should be `logging.exception("blah", ..., extra={'request':request})` like many other parts of the Djblets/ReviewBoard codebase. If middleware.py is fixed, the same problem happens again in reviewboard/diffviewer/views.py. File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/core/handlers/base.py" in get_response 112. response = wrapped_callback(request, *callback_args, **callback_kwargs) File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/views/generic/base.py" in view 69. return self.dispatch(request, *args, **kwargs) File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/utils/decorators.py" in _wrapper 29. return bound_func(*args, **kwargs) File "/usr/lib/python2.6/site-packages/ReviewBoard-2.5.8-py2.6.egg/reviewboard/accounts/decorators.py" in _check 23. return login_required(view_func)(*args, **kwargs) File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/contrib/auth/decorators.py" in _wrapped_view 22. return view_func(request, *args, **kwargs) File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/utils/decorators.py" in bound_func 25. return func(self, *args2, **kwargs2) File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/utils/decorators.py" in _wrapper 29. return bound_func(*args, **kwargs) File "/usr/lib/python2.6/site-packages/ReviewBoard-2.5.8-py2.6.egg/reviewboard/site/decorators.py" in _check 35. return view_func(request, local_site=local_site, *args, **kwargs) File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/utils/decorators.py" in bound_func 25. return func(self, *args2, **kwargs2) File "/usr/lib/python2.6/site-packages/Djblets-0.9.5-py2.6.egg/djblets/util/decorators.py" in _call 75. f = augmented_func(*args, **kwargs) File "/usr/lib/python2.6/site-packages/Django-1.6.11-py2.6.egg/django/views/generic/base.py" in dispatch 87. return handler(request, *args, **kwargs) File "/usr/lib/python2.6/site-packages/ReviewBoard-2.5.8-py2.6.egg/reviewboard/diffviewer/views.py" in get 309. request=request) Exception Type: TypeError at /reviews/r/1465/diff/1/fragment/24145/ Exception Value: exception() got an unexpected keyword argument 'request' If that's fixed, finally ReviewBoard works correctly: it reports that the diff didn't apply cleanly. I looked for all usages of `logging.loggingmethod()` (error, warning, exception, debug, critical, info, log) with keyword args in them, and came down to this: In Djblets-0.9.5: djblets/webapi/auth/backends/api_tokens.py: logging.warning('WebAPITokenAuthBackend: Missing token in ' 'HTTP_AUTHORIZATION header %s', http_auth, extra={'request': request}) djblets/webapi/auth/backends/basic.py: logging.warning("Failed to parse HTTP_AUTHORIZATION header %s" % request.META['HTTP_AUTHORIZATION'], exc_info=1, extra={'request': request}) djblets/webapi/auth/backends/base.py: logging.debug( 'Attempting authentication on API: %s', ', '.join([ '%s=%s' % pair for pair in six.iteritems(cleaned_credentials) ]), extra=log_extra) djblets/webapi/auth/backends/base.py: logging.debug('API Login failed. No valid user found.', extra=log_extra) djblets/datagrid/grids.py: logging.error("Unable to load template '%s' for datagrid " "cell. This may be an installation issue.", self.cell_template, extra={ 'request': self.request, }) djblets/datagrid/grids.py: logging.error("Unable to load template '%s' for datagrid " "column headers. This may be an installation " "issue.", self.column_header_template, extra={ 'request': self.request, }) djblets/log/__init__.py: logging.log(self.default_level, "Begin: %s" % self.message, request=self.request) djblets/log/__init__.py: logging.log(self.default_level, "End: %s" % self.message, request=self.request) djblets/log/__init__.py: logging.log(level, '%s took %d.%06d seconds' % (self.message, delta.seconds, delta.microseconds), request=self.request) djblets/log/middleware.py: logging.exception('Exception thrown for user %s at %s\n\n%s', request.user, request.build_absolute_uri(), exception, request=request) In ReviewBoard-2.5.8: reviewboard/webapi/resources/base_file_attachment.py: logging.error( 'Failed to store thumbnail for attachment %d: %s', file.pk, e, request=request) reviewboard/webapi/resources/repository.py: logging.error('Got unexpected SSHError when checking ' 'repository: %s' % e, exc_info=1, request=request) reviewboard/webapi/resources/repository.py: logging.error('Got unexpected SCMError when checking ' 'repository: %s' % e, exc_info=1, request=request) reviewboard/webapi/resources/repository.py: logging.error('Unknown error in checking repository %s: %s', path, e, exc_info=1, request=request) reviewboard/webapi/resources/base_patched_file.py: logging.error('%s: Error retrieving original file for FileDiff ' '%s: %s', self.__class__.__name__, filediff.pk, e, exc_info=1, request=request) reviewboard/webapi/resources/base_patched_file.py: logging.error('%s: Error retrieving patched file for FileDiff %' '%s: %s', self.__class__.__name__, filediff.pk, e, exc_info=1, request=request) reviewboard/webapi/resources/base_original_file.py: logging.error('%s: Error retrieving original file for FileDiff ' '%s: %s', self.__class__.__name__, filediff.pk, e, exc_info=1, request=request) reviewboard/webapi/resources/diff.py: logging.error("Error uploading new diff: %s", e, exc_info=1, request=request) reviewboard/reviews/models/group.py: logging.warning('Group pk=%d (%s) is not accessible by user ' '%s because its local_site is not accessible ' 'by that user.', self.pk, self.name, user, request=request) reviewboard/reviews/models/group.py: logging.warning('Group pk=%d (%s) is not accessible by user %s ' 'because it is invite only, and the user is not a ' 'member.', self.pk, self.name, user, request=request) reviewboard/reviews/models/review_request.py: logging.warning('Review Request pk=%d (display_id=%d) is not ' 'accessible by user %s because it has not yet ' 'been published.', self.pk, self.display_id, user, request=request) reviewboard/reviews/models/review_request.py: logging.warning('Review Request pk=%d (display_id=%d) is not ' 'accessible by user %s because its repository ' 'is not accessible by that user.', self.pk, self.display_id, user, request=request) reviewboard/reviews/models/review_request.py: logging.warning('Review Request pk=%d (display_id=%d) is not ' 'accessible by user %s because its local_site ' 'is not accessible by that user.', self.pk, self.display_id, user, request=request) reviewboard/reviews/models/review_request.py: logging.warning('Review Request pk=%d (display_id=%d) is not ' 'accessible by user %s because they are not ' 'directly listed as a reviewer, and none of ' 'the target groups are accessible by that user.', self.pk, self.display_id, user, request=request) reviewboard/diffviewer/views.py: logging.debug('Generating diff viewer page for interdiffset ' 'ids %s-%s', diffset.id, interdiffset.id, request=request) reviewboard/diffviewer/views.py: logging.debug('Generating diff viewer page for filediff id %s', diffset.id, request=request) reviewboard/diffviewer/views.py: logging.debug('Done generating diff viewer page for ' 'interdiffset ids %s-%s', diffset.id, interdiffset.id, request=request) reviewboard/diffviewer/views.py: logging.debug('Done generating diff viewer page for filediff ' 'id %s', diffset.id, request=request) reviewboard/diffviewer/views.py: logging.exception('%s.get: Error rendering diff for diffset ' 'ID=%s, interdiffset ID=%s: %s', self.__class__.__name__, diffset.pk, interdiffset_id, e, request=request) reviewboard/diffviewer/views.py: logging.exception('%s.get: Error when processing diffset info ' 'for filediff ID=%s, interfilediff ID=%s, ' 'chunkindex=%s: %s', self.__class__.__name__, kwargs.get('filediff_id'), kwargs.get('interfilediff_id'), kwargs.get('chunkindex'), e, request=request) reviewboard/diffviewer/views.py: logging.exception('%s.get: Error when rendering diffset for ' 'filediff ID=%s, interfilediff ID=%s, ' 'chunkindex=%s: %s', self.__class__.__name__, kwargs.get('filediff_id'), kwargs.get('interfilediff_id'), kwargs.get('chunkindex'), e, request=request) Which, when made entirely generic (replacing strings and multiple-arguments with test arguments), becomes this: logging.debug('test %s', 'test', extra=None) logging.debug('test', extra=None) logging.debug('test %s', 'test', request=None) logging.error('test %s', 'test', request=None) logging.error('test %s', 'test', exc_info=1, request=None) logging.error('test %s', 'test', extra={'request': None}) logging.exception('test %s', 'test', request=None) logging.log(logging.INFO, 'test', request=None) logging.warning('test', exc_info=1, extra={'request': None}) logging.warning('test %s', 'test', request=None) logging.warning('test %s', 'test', extra={'request': None}) I then tested running these in Python 3.5.2: These work: * logging.debug('test %s', 'test', extra=None) * logging.debug('test', extra=None) * logging.debug('test %s', 'test', request=None) * logging.error('test %s', 'test', extra={'request': None}) * logging.log(logging.INFO, 'test', request=None) * logging.warning('test', exc_info=1, extra={'request': None}) * logging.warning('test %s', 'test', extra={'request': None}) These fail: * logging.error('test %s', 'test', request=None) * logging.error('test %s', 'test', exc_info=1, request=None) * logging.exception('test %s', 'test', request=None) * logging.warning('test %s', 'test', request=None) So in the code base, I've changed all "request=request" in logging.error(), logging.exception(), logging.warning() to extra={'request':request} ------------------------------------------------------------------------------ -- You received this message because you are subscribed to the Google Groups "reviewboard-issues" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To post to this group, send email to [email protected]. Visit this group at https://groups.google.com/group/reviewboard-issues. For more options, visit https://groups.google.com/d/optout.
