0003-allow-ressources-to-disable-error-logging-in-request.patch

Benjamin Dauvergne, 08 mars 2019 01:16

Voir les différences: en ligne côte à côte

Subject: [PATCH 3/4] allow ressources to disable error logging in requests
 wrapper (#31114)

- modify ProxyLogger to get request from the "extra" parameter like Django, it
  incurs that we need to clean extra from non JSON-serializable values
  before using it in the ResourceLog model.

- modify to_json() so that request is passed to every log calls as
  before commit 5286592cf, now we will get error mails containing Django
  request details.

- resource can set "log_requests_errors = False" so that the Request
  wrapper never log at the error/warning level.

- small annoyance: requests errors are logged two times, at the INFO
  level and the ERROR level.

- connector MDPH13 is adapted to use all this.

 passerelle/base/models.py           | 11 +++--
 passerelle/contrib/mdph13/models.py | 74 +++++++++++------------------
 passerelle/utils/__init__.py        | 71 ++++++++++++++-------------
 passerelle/utils/jsonresponse.py    | 18 +++++--
 passerelle/views.py                 |  2 +-
 tests/test_mdph13.py                | 31 +++++++++++-
 6 files changed, 118 insertions(+), 89 deletions(-)

     from django.db.models import Q
     from django.test import override_settings
     from django.utils.text import slugify
     from django.utils import timezone
     from django.utils import timezone, six
     from django.utils.translation import ugettext_lazy as _
     from django.core.files.base import ContentFile
-...
                 attr['appname'] = self.appname
                 attr['slug'] = self.slug
                 attr['extra'] = kwargs.get('extra', {})
                 request = kwargs.pop('request', None)
                 extra = kwargs.get('extra', {})
                 request = extra.get('request')
                 def is_json_serializable(value):
                     return isinstance(value, (list, dict) + six.integer_types + six.string_types)
                 attr['extra'] = {key: value for key, value in extra.items() if is_json_serializable(value)}
                 if getattr(request, 'META', None):
                     if 'HTTP_X_FORWARDED_FOR' in request.META:

     # You should have received a copy of the GNU Affero General Public License
     # along with this program.  If not, see <http://www.gnu.org/licenses/>.
     import sys
     import base64
     import urlparse
     import datetime
-...
         else:
             func(value, path)
     ERROR_MAPPING = {
         'dossier-inconnu': 'dossier-inconnu',
         'secret-invalide': 'secret-invalide',
         'dateNaissance-erronee': 'date-de-naissance-erronee',
+    }
     class MDPH13Resource(BaseResource, HTTPResource):
         category = _('Business Process Connectors')
-...
         EMAIL_RE = re.compile(r'^[^@\s]+@[^@\s]+\.[^@\s]+$')
         DATE_RE = re.compile(r'^\d{4}-\d{2}-\d{2}$')
         log_requests_errors = False
         class Meta:
             verbose_name = _('MDPH CD13')
-...
             return urlparse.urljoin(self.webservice_base_url, 'situation/dossier/%s' % file_number)
         def url_get(self, *args, **kwargs):
             try:
                 response = None
                 response = self.requests.get(*args, **kwargs)
                 response.raise_for_status()
             except requests.RequestException as e:
                 data = {'exception': six.text_type(e)}
                 if response is not None:
                     try:
                         if response.json():
                             data['body'] = response.json()
                     except ValueError:
                         body = response.content[:1000]
                         if len(response.content) > 1000:
                             body += b'<SNIPPED>'
                         data['body'] = repr(body)
                     data['status_code'] = response.status_code
                 raise APIError('HTTP request failed', data=data)
             response = self.requests.get(*args, **kwargs)
             try:
                 content = response.json()
             except ValueError as e:
                 data = {'exception': six.text_type(e)}
                 data['body'] = '%r<SNIPPED>' % response.content[:1000]
                 raise APIError('HTTP request did not respond with JSON', data=data)
             except ValueError:
                 response.raise_for_status()
                 raise requests.RequestException('JSON expected', response=response)
             if content.get('err') != 0:
                 err_desc = ERROR_MAPPING.get(
                     content.get('err_code'),
                     'err != 0: missing or unknown error code')
                 raise APIError(err_desc, data=content)
             response.raise_for_status()
             return content
         def call_situation_dossier(self, file_number, secret, dob, email=None):
             url = self.situation_dossier_url(file_number)
             email = email or 'appel-sans-utilisateur@cd13.fr'
             error_mapping = {
                 'dossier-inconnu': 'dossier-inconnu',
                 'secret-invalide': 'secret-invalide',
                 'dateNaissance-erronee': 'date-de-naissance-erronee',
+            }
             try:
                 content = self.url_get(
                     url,
                     headers={
                         'X-CD13-Secret': base64.b64encode(secret.encode('utf-8')).decode('ascii'),
                         'X-CD13-Email': email,
                         'X-CD13-DateNaissBenef': dob.isoformat(),
                     })
             except APIError as e:
                 if e.data and e.data.get('status_code') == 404 and isinstance(e.data.get('body'), dict):
                     content = e.data['body']
                     if content.get('err') != 0:
                         error_code = content.get('err_code')
                         err_desc = error_mapping.get(error_code, 'err != 0')
                         raise APIError(err_desc, data=e.data)
                 raise
             if content.get('err') != 0:
                 error_code = content.get('err_code')
                 err_desc = error_mapping.get(error_code, 'err != 0')
                 raise APIError(err_desc, data=content)
             content = self.url_get(
                 url,
                 headers={
                     'X-CD13-Secret': base64.b64encode(secret.encode('utf-8')).decode('ascii'),
                     'X-CD13-Email': email,
                     'X-CD13-DateNaissBenef': dob.isoformat(),
                 })
             data = content.get('data')
             if not isinstance(data, dict):

     from passerelle.base.models import ApiUser, AccessRight, BaseResource
     from passerelle.base.signature import check_query, check_url
     # legacy import, other modules keep importing to_json from passerelle.utils
     from .jsonresponse import to_json
     def get_template_vars():
         """
-...
         return False
     def log_http_request(logger, request, response=None, exception=None, error_log=True, extra=None):
         log_function = logger.info
         message = '%s %s' % (request.method, request.url)
         extra = extra or {}
         extra['request_url'] = request.url
         if logger.level == 10:  # DEBUG
             extra['request_headers'] = dict(request.headers.items())
             if request.body:
                 extra['request_payload'] = repr(request.body[:5000])
         if response is not None:
             message = message + ' (=> %s)' % response.status_code
             extra['response_status'] = response.status_code
             if logger.level == 10:  # DEBUG
                 extra['response_headers'] = dict(response.headers.items())
                 # log body only if content type is allowed
                 if content_type_match(response.headers.get('Content-Type')):
                     content = response.content[:settings.LOGGED_RESPONSES_MAX_SIZE]
                     extra['response_content'] = repr(content)
             if response.status_code // 100 == 3:
                 log_function = logger.warning
             elif response.status_code // 100 >= 4:
                 log_function = logger.error
         elif exception:
             message = message + ' (=> %s)' % repr(exception)
             extra['response_exception'] = repr(exception)
             log_function = logger.error
         # allow resources to disable any error log at requests level
         if not error_log:
             log_function = logger.info
         log_function(message, extra=extra)
     # Wrapper around requests.Session
     # - log input and output data
     # - use HTTP Basic auth if resource.basic_auth_username and resource.basic_auth_password exist
-...
     # - use a proxy for HTTP and HTTPS if resource.http_proxy exists
     class Request(RequestSession):
         def __init__(self, *args, **kwargs):
             self.logger = kwargs.pop('logger')
             self.resource = kwargs.pop('resource', None)
-...
             except Exception as exc:
                 self.log_http_request(request, exception=exc)
                 raise
             self.log_http_request(request, response)
             self.log_http_request(request, response=response)
             return response
         def log_http_request(self, request, response=None, exception=None):
             message = '%s %s' % (request.method, request.url)
             extra = {}
             extra['request_url'] = request.url
             if self.logger.level == 10:  # DEBUG
                 extra['request_headers'] = dict(request.headers.items())
                 if request.body:
                     extra['request_payload'] = repr(request.body[:5000])
             log_function = self.logger.info
             if response is not None:
                 message = message + ' (=> %s)' % response.status_code
                 extra['response_status'] = response.status_code
                 if self.logger.level == 10:  # DEBUG
                     extra['response_headers'] = dict(response.headers.items())
                     # log body only if content type is allowed
                     if content_type_match(response.headers.get('Content-Type')):
                         content = response.content[:settings.LOGGED_RESPONSES_MAX_SIZE]
                         extra['response_content'] = repr(content)
                 if response.status_code // 100 == 3:
                     log_function = self.logger.warning
                 elif response.status_code // 100 >= 4:
                     log_function = self.logger.error
             elif exception:
                 message = message + ' (=> %s)' % repr(exception)
                 extra['response_exception'] = repr(exception)
                 log_function = self.logger.error
             log_function(message, extra=extra)
             error_log = getattr(self.resource, 'log_requests_errors', True)
             log_http_request(self.logger, request=request, response=response, exception=exception, error_log=error_log)
     class SOAPClient(Client):
-...
             # call next() at least one time to advance, if the caller does not
             # consume the returned iterators, sourceiter will never be exhausted.
             yield chain([batchiter.next()], batchiter)
     # legacy import, other modules keep importing to_json from passerelle.utils
     from .jsonresponse import to_json

     from django.utils.translation import force_text
     from django.utils import six
     from requests.exceptions import RequestException
     from requests import RequestException, HTTPError
     from passerelle.utils import log_http_request
     DEFAULT_DEBUG = getattr(settings, 'JSONRESPONSE_DEFAULT_DEBUG', False)
-...
                 data = self.obj_to_response(req, resp)
                 status = 200
             except Exception as e:
                 extras = {'method': req.method, 'exception': exception_to_text(e)}
                 if not self.logger:
                     extras['request'] = req
                 extras = {'method': req.method, 'exception': exception_to_text(e), 'request': req}
                 if req.method == 'POST':
                     extras.update({'body': repr(req.body[:5000])})
                 if (not isinstance(e, (Http404, PermissionDenied, ObjectDoesNotExist, RequestException))
-...
                     logger.warning('object not found: %r', e, extra=extras)
                 elif isinstance(e, PermissionDenied):
                     logger.warning('Permission denied', extra=extras)
                 elif isinstance(e, HTTPError):
                     log_http_request(logger,
                                      request=e.request,
                                      response=e.response,
                                      extra=extras)
                 elif isinstance(e, RequestException):
                     logger.warning("RequestException occurred while processing request", extra=extras)
                     log_http_request(logger,
                                      request=e.request,
                                      exception=e,
                                      extra=extras)
                 elif isinstance(e, Http404):
                     # Http404 is for silent object not found exceptions
                     pass

                 payload = '<BINARY PAYLOAD>'
             connector.logger.info('endpoint %s %s (%r) ' %
                                   (request.method, url, payload),
                                   request=request,
                                   extra={
                                       'request': request,
                                       'connector': connector_name,
                                       'connector_endpoint': endpoint_name,
                                       'connector_endpoint_method': request.method,

     import json
     import base64
     import datetime
     import logging
     import requests
     import requests.exceptions
     import httmock
     import pytest
-...
             def request_handler(self, url, request):
                 idx = len(self.requests)
                 self.requests.append(request)
                 return self.responses[idx]
                 response = self.responses[idx]
                 if isinstance(response, Exception):
                     raise response
                 elif hasattr(response, '__call__'):
                     response = response(url, request)
                 return response
         mock_http = MockHttp()
         with httmock.HTTMock(httmock.urlmatch()(mock_http.request_handler)):
-...
         with pytest.raises(APIError) as exc_info:
             mdph13.dossiers(None, NAME_ID, EMAIL, link_id=str(link.pk))
         assert str(exc_info.value) == 'invalid-response-format'
     def test_dossier_http_error(app, mdph13, mock_http, caplog):
         url = '/mdph13/test1/link/?NameID=%s&numero_dossier=%s&date_de_naissance=%s&secret=%s&email=%s'
         url = url % (NAME_ID, FILE_NUMBER, DOB, SECRET, EMAIL)
         mock_http.add_response({'status_code': 401, 'content': 'wtf', 'reason': 'Authentication required'})
         response = app.post(url, status=500)
         assert response.json['err_class'] == 'requests.exceptions.HTTPError'
         assert caplog.records[-1].levelno == logging.ERROR
         assert caplog.records[-1].getMessage() == 'GET http://cd13.fr/situation/dossier/1234 (=> 401)'
         assert hasattr(caplog.records[-1].request, 'META')
         def raise_ssl_error(url, request):
             raise requests.exceptions.SSLError(request=request)
         mock_http.add_response(raise_ssl_error)
         response = app.post(url, status=500)
         assert response.json['err_class'] == 'requests.exceptions.SSLError'
         assert caplog.records[-1].levelno == logging.ERROR
         assert caplog.records[-1].getMessage() == 'GET http://cd13.fr/situation/dossier/1234 (=> SSLError())'
         assert hasattr(caplog.records[-1].request, 'META')
+    -

Projet

Général

Profil

Produits Entr'ouvert » Passerelle

0003-allow-ressources-to-disable-error-logging-in-request.patch