Merge pull request #17 from luizalabs/access_log_middleware

create access log middleware

.travis.yml

@@ -9,8 +9,15 @@ cache:
     - $HOME/.cache/pip
 
 install:
+  - pip install "$DJANGO"
   - pip install -r requirements-dev.txt
 
+env:
+  matrix:
+   - DJANGO="Django<1.9"
+   - DJANGO="Django<1.10"
+   - DJANGO="Django<1.11"
+
 script:
   - make check coverage
 

Makefile

@@ -14,7 +14,7 @@ check:  ## Run static code checks
 	@flake8 .
 	@isort --check
 
-test:  ## Run unit tests
+test: clean ## Run unit tests
 	@py.test -x tests/
 
 coverage:  ## Run unit tests and generate code coverage report

django_toolkit/fallbacks/circuit_breaker.py

@@ -1,3 +1,4 @@
+# -*- coding: utf-8 -*-
 import logging
 
 logger = logging.getLogger(__name__)

django_toolkit/middlewares.py

@@ -1,13 +1,43 @@
 # -*- coding: utf-8 -*-
-from django.conf import settings
+import logging
 
+from .shortcuts import get_oauth2_app
+from .toolkit_settings import API_VERSION, MIDDLEWARE_ACCESS_LOG_FORMAT
 
-class VersionHeaderMiddleware(object):
+try:
+    from django.utils.deprecation import MiddlewareMixin
+except ImportError:
+    MiddlewareMixin = object
+
+
+logger = logging.getLogger(__name__)
+
+
+class VersionHeaderMiddleware(MiddlewareMixin):
     """
     Add a X-API-Version header to the response. The version is taken from
     TOOLKIT['API_VERSION'] setting.
     """
 
     def process_response(self, request, response):
-        response['X-API-Version'] = settings.TOOLKIT['API_VERSION']
+        response['X-API-Version'] = API_VERSION
+        return response
+
+
+class AccessLogMiddleware(MiddlewareMixin):
+
+    LOG_FORMAT = MIDDLEWARE_ACCESS_LOG_FORMAT
+    UNKNOWN_APP_NAME = 'unknown'
+
+    def process_response(self, request, response):
+        app = get_oauth2_app(request)
+
+        app_name = getattr(app, 'name', self.UNKNOWN_APP_NAME)
+
+        logger.info(
+            self.LOG_FORMAT.format(app_name=app_name,
+                                   request=request,
+                                   response=response)
+        )
+
         return response

django_toolkit/toolkit_settings.py

@@ -6,3 +6,10 @@
     'ACCESS_TOKEN_CACHE_BACKEND',
     'access_token'
 )
+
+API_VERSION = _toolkit_settings.get('API_VERSION')
+
+MIDDLEWARE_ACCESS_LOG_FORMAT = _toolkit_settings.get(
+    'MIDDLEWARE_ACCESS_LOG_FORMAT',
+    u'[{app_name}] {response.status_code} {request.method} {request.path}'
+)

docs/middlewares.md

@@ -5,7 +5,7 @@ Middlewares
 It’s a light, low-level “plugin” system for globally altering Django’s input
 or output.
 >
->— [Python Docs][cite]
+>— [Django Docs][cite]
 
 [cite]: https://docs.djangoproject.com/pt-br/1.9/topics/http/middleware/
 
@@ -20,3 +20,23 @@ Middlewares must be [registered][register-middleware] in the Django's
 
 Adds a `X-API-Version` header to the Django's response. In order to use this
 middleware, you should fill the `API_VERSION` key in the `TOOLKIT` setting.
+
+
+### AccessLogMiddleware
+
+`django_toolkit.middlewares.AccessLogMiddleware`
+
+Creates an access log entry with this format:
+
+```
+[{app_name}] {response.status_code} {request.method} {request.path}
+```
+
+You can specify the log format in the `TOOLKIT` settings variable.
+Example:
+
+```python
+# toolkit settings
+TOOLKIT = {
+    'MIDDLEWARE_ACCESS_LOG_FORMAT': '{app_name} {request.method} {response.status_code}'
+}

requirements-dev.txt

@@ -1,12 +1,12 @@
 -e .
 bumpversion==0.5.3
 django-oauth-toolkit==0.10.0
-djangorestframework==3.5.2
+djangorestframework==3.5.3
 flake8==3.0.4
 isort==4.2.5
 mixer==5.5.8
-mkdocs==0.15.3
+mkdocs==0.16.0
 mock==2.0.0
 pytest-cov==2.4.0
 pytest-django==3.0.0
-pytest==3.0.3
+pytest==3.0.4

tests/test_middlewares.py

@@ -2,10 +2,21 @@
 import pytest
 from django.conf import settings
 from django.http import HttpResponse
+from mock import Mock, PropertyMock, patch
 
 from django_toolkit import middlewares
 
 
+@pytest.fixture
+def http_request(rf):
+    return rf.get('/')
+
+
+@pytest.fixture
+def http_response():
+    return HttpResponse()
+
+
 class TestVersionHeaderMiddleware(object):
 
     @pytest.fixture(autouse=True)
@@ -19,14 +30,6 @@ def settings(self, settings):
     def middleware(self):
         return middlewares.VersionHeaderMiddleware()
 
-    @pytest.fixture
-    def http_request(self, rf):
-        return rf.get('/')
-
-    @pytest.fixture
-    def http_response(self):
-        return HttpResponse()
-
     def test_should_return_a_response(
         self,
         middleware,
@@ -46,3 +49,97 @@ def test_should_add_a_version_header_to_the_response(
 
         assert 'X-API-Version' in response
         assert response['X-API-Version'] == settings.TOOLKIT['API_VERSION']
+
+
+@pytest.mark.django_db
+class TestAccessLogMiddleware(object):
+
+    @pytest.fixture
+    def middleware(self):
+        return middlewares.AccessLogMiddleware()
+
+    @pytest.fixture
+    def patched_logger(self):
+        return patch('django_toolkit.middlewares.logger')
+
+    @pytest.fixture
+    def patched_format(self):
+        return patch(
+            'django_toolkit.middlewares.AccessLogMiddleware.LOG_FORMAT',
+            new_callable=PropertyMock
+        )
+
+    @pytest.fixture
+    def authenticated_http_request(self, http_request):
+        http_request.user = u'jovem'
+        http_request.auth = Mock(application=Mock(name='myapp'))
+        return http_request
+
+    def test_should_return_a_response(
+        self,
+        middleware,
+        http_request,
+        http_response
+    ):
+        response = middleware.process_response(http_request, http_response)
+        assert isinstance(response, HttpResponse)
+
+    def test_should_log_responses(
+        self,
+        middleware,
+        http_request,
+        http_response,
+        patched_logger,
+        patched_format
+    ):
+        with patched_logger as mock_logger:
+            middleware.process_response(http_request, http_response)
+
+        assert mock_logger.info.called
+
+    def test_should_include_request_and_response_in_the_message(
+        self,
+        middleware,
+        http_request,
+        http_response,
+        patched_logger,
+        patched_format
+    ):
+        with patched_logger as mock_logger:
+            with patched_format as mock_format_property:
+                middleware.process_response(http_request, http_response)
+
+        mock_format_string = mock_format_property.return_value
+
+        assert mock_format_string.format.called
+        mock_format_string.format.assert_called_once_with(
+            app_name=middleware.UNKNOWN_APP_NAME,
+            request=http_request,
+            response=http_response
+        )
+        mock_logger.info.assert_called_once_with(
+            mock_format_string.format.return_value
+        )
+
+    def test_should_include_the_authenticated_app_in_the_message(
+        self,
+        middleware,
+        authenticated_http_request,
+        http_response,
+        patched_logger,
+        patched_format
+    ):
+        with patched_format as mock_format_property:
+            middleware.process_response(
+                authenticated_http_request,
+                http_response
+            )
+
+        mock_format_string = mock_format_property.return_value
+
+        assert mock_format_string.format.called
+        mock_format_string.format.assert_called_once_with(
+            app_name=authenticated_http_request.auth.application.name,
+            request=authenticated_http_request,
+            response=http_response
+        )