559-endpoint-log-events - Adds middleware for calling analytics events for each endpoint

src/fidesops/main.py

@@ -47,44 +47,26 @@
 async def dispatch_log_request(request: Request, call_next: Callable) -> Response:
     fides_source: Optional[str] = request.headers.get("X-Fides-Source")
     now: datetime = datetime.now(tz=timezone.utc)
-    endpoint = f"{request.method}: {request.url.path}"
+    endpoint = f"{request.method}: {request.url}"
 
     try:
         response = await call_next(request)
         # HTTPExceptions are considered a handled err by default so are not thrown here.
         # Accepted workaround is to inspect status code of response.
         # More context- https://github.com/tiangolo/fastapi/issues/1840
-        try:
-            if response.status_code >= 400:
-                response.background = BackgroundTask(
-                    prepare_and_log_request,
-                    endpoint,
-                    response.status_code,
-                    now,
-                    fides_source,
-                    "HTTPException",
-                )
-            else:
-                response.background = BackgroundTask(
-                    prepare_and_log_request,
-                    endpoint,
-                    response.status_code,
-                    now,
-                    fides_source,
-                    None,
-                )
-        except Exception as exc:
-            # always continue if something went wrong with analytics
-            logger.warning(
-                f"Analytics event for endpoint {request.url} failed to send: {exc}"
-            )
-            return response
+        response.background = BackgroundTask(
+            prepare_and_log_request,
+            endpoint,
+            response.status_code,
+            now,
+            fides_source,
+            "HTTPException" if response.status_code >= 400 else None
+        )
 
         return response
     except Exception as e:
-        logger.warning("exception caught")
         prepare_and_log_request(
-            endpoint, e.args[0], now, fides_source, e.__class__.__name__
+            endpoint, 500, now, fides_source, e.__class__.__name__
         )
         raise
 

src/fidesops/task/graph_task.py

@@ -63,9 +63,6 @@ def result(*args: Any, **kwargs: Any) -> List[Optional[Row]]:
             self = args[0]
 
             raised_ex = None
-            if config.dev_mode:
-                # If dev mode, return here so exception isn't caught
-                return func(*args, **kwargs)
             for attempt in range(config.execution.TASK_RETRY_COUNT + 1):
                 try:
                     self.skip_if_disabled()

tests/conftest.py

@@ -162,3 +162,12 @@ def integration_config() -> MutableMapping[str, Any]:
 def celery_enable_logging():
     """Turns on celery output logs."""
     return True
+
+
+@pytest.fixture(autouse=True, scope="session")
+def analytics_opt_out():
+    """Disable sending analytics when running tests."""
+    original_value = config.root_user.ANALYTICS_OPT_OUT
+    config.root_user.ANALYTICS_OPT_OUT = True
+    yield
+    config.root_user.ANALYTICS_OPT_OUT = original_value

tests/graph/test_graph.py

@@ -70,7 +70,6 @@ def test_retry_decorator(privacy_request, policy):
         CollectionAddress("postgres_example", "payment_card")
     ]
 
-    config.dev_mode = False
     config.execution.TASK_RETRY_COUNT = 5
     config.execution.TASK_RETRY_DELAY = 0.1
     config.execution.TASK_RETRY_BACKOFF = 0.01

tests/integration_tests/test_execution.py

@@ -184,8 +184,6 @@ def test_collection_omitted_on_restart_from_failure(
         """Remove secrets to make privacy request fail, then delete the connection config. Build a graph
         that does not contain the deleted dataset config and re-run."""
 
-        config.dev_mode = False
-
         integration_mongodb_config.secrets = {}
         integration_mongodb_config.save(db)
 
@@ -441,8 +439,6 @@ def test_skip_collection_on_restart(
         """Remove secrets to make privacy request fail, then disable connection config
         and confirm that datastores are skipped on re-run"""
 
-        config.dev_mode = False
-
         integration_mongodb_config.secrets = {}
         integration_mongodb_config.save(db)
 
@@ -567,8 +563,6 @@ def test_restart_graph_from_failure(
 ) -> None:
     """Run a failed privacy request and restart from failure"""
 
-    config.dev_mode = False
-
     privacy_request = PrivacyRequest(
         id=f"test_postgres_access_request_task_{uuid.uuid4()}"
     )

tests/integration_tests/test_manual_task.py

@@ -27,7 +27,6 @@ def test_postgres_with_manual_input_access_request_task(
     integration_manual_config,
 ) -> None:
     """Run a privacy request with two manual nodes"""
-    config.dev_mode = False
     privacy_request = PrivacyRequest(
         id=f"test_postgres_access_request_task_{uuid.uuid4()}"
     )

tests/integration_tests/test_sql_task.py

@@ -956,7 +956,6 @@ def test_retry_access_request(
         policy,
         integration_postgres_config,
     ):
-        config.dev_mode = False
         config.execution.TASK_RETRY_COUNT = 1
         config.execution.TASK_RETRY_DELAY = 0.1
         config.execution.TASK_RETRY_BACKOFF = 0.01
@@ -1008,7 +1007,6 @@ def test_retry_erasure(
         policy,
         integration_postgres_config,
     ):
-        config.dev_mode = False
         config.execution.TASK_RETRY_COUNT = 2
         config.execution.TASK_RETRY_DELAY = 0.1
         config.execution.TASK_RETRY_BACKOFF = 0.01

tests/test_main.py

@@ -0,0 +1,139 @@
+import asyncio
+from datetime import datetime, timezone
+from typing import Any
+from unittest import mock
+from unittest.mock import Mock
+
+import pytest
+from fideslog.sdk.python.event import AnalyticsEvent
+from starlette.requests import Request
+from starlette.responses import Response
+
+from fidesops.analytics import in_docker_container, running_on_local_host
+from fidesops.main import dispatch_log_request
+from fidesops.schemas.analytics import Event
+from fidesops.util.async_util import wait_for
+
+
+class CustomTestException(BaseException):
+    """Mock Non-HTTP Exception"""
+    pass
+
+
+@mock.patch("fidesops.analytics.send_analytics_event")
+@mock.patch("datetime.datetime")
+def test_dispatch_log_request_no_exception(
+        datetime_mock: Mock,
+        send_analytics_request_mock: Mock,
+) -> None:
+    request = Request(
+        scope={
+            "type": "http",
+            "method": 'GET',
+            "path": "/testing",
+            "server": {
+                "host": "www.testsite.com",
+                "port": 3000
+            },
+            "headers": {}
+        },
+    )
+
+    datetime_mock.now.return_value = datetime(2022, 5, 22, tzinfo=timezone.utc)
+
+    f = asyncio.Future()
+    f.set_result(Response(status_code=200))
+
+    def mock_call_next(request: Request) -> Any:
+        return f
+
+    wait_for(dispatch_log_request(request, mock_call_next))
+    assert send_analytics_request_mock.assert_called_once_with(
+        AnalyticsEvent(
+            docker=in_docker_container(),
+            event=Event.endpoint_call.value,
+            event_created_at=datetime_mock.now.return_value,
+            local_host=running_on_local_host(),
+            endpoint="GET: http://www.testsite.com/testing",
+            status_code=200,
+        )
+    )
+
+
+@mock.patch("fidesops.analytics.send_analytics_event")
+@mock.patch("datetime.datetime")
+def test_dispatch_log_request_http_exception(
+        datetime_mock: Mock,
+        send_analytics_request_mock: Mock,
+) -> None:
+    request = Request(
+        scope={
+            "type": "http",
+            "method": 'GET',
+            "path": "/testing",
+            "server": {
+                "host": "www.testsite.com",
+                "port": 3000
+            },
+            "headers": {}
+        },
+    )
+
+    datetime_mock.now.return_value = datetime(2022, 5, 22, tzinfo=timezone.utc)
+
+    f = asyncio.Future()
+    f.set_result(Response(status_code=404))
+
+    def mock_call_next(request: Request) -> Any:
+        return f
+
+    wait_for(dispatch_log_request(request, mock_call_next))
+    assert send_analytics_request_mock.assert_called_once_with(
+        AnalyticsEvent(
+            docker=in_docker_container(),
+            event=Event.endpoint_call.value,
+            event_created_at=datetime_mock.now.return_value,
+            local_host=running_on_local_host(),
+            endpoint="GET: http://www.testsite.com/testing",
+            status_code=404,
+        )
+    )
+
+
+@mock.patch("fidesops.analytics.send_analytics_event")
+@mock.patch("datetime.datetime")
+def test_dispatch_log_request_other_exception(
+        datetime_mock: Mock,
+        send_analytics_request_mock: Mock,
+) -> None:
+    request = Request(
+        scope={
+            "type": "http",
+            "method": 'GET',
+            "path": "/testing",
+            "server": {
+                "host": "www.testsite.com",
+                "port": 3000
+            },
+            "headers": {}
+        },
+    )
+
+    datetime_mock.now.return_value = datetime(2022, 5, 22)
+
+    def mock_call_next(request: Request) -> Any:
+        raise CustomTestException(BaseException)
+
+    with pytest.raises(CustomTestException):
+        wait_for(dispatch_log_request(request, mock_call_next))
+        assert send_analytics_request_mock.assert_called_once_with(
+            AnalyticsEvent(
+                docker=in_docker_container(),
+                event=Event.endpoint_call.value,
+                event_created_at=datetime_mock.now.return_value,
+                local_host=running_on_local_host(),
+                endpoint="GET: http://www.testsite.com/testing",
+                status_code=500,
+                error="CustomTestException"
+            )
+        )