MPP-4012 - feat(glean): log API access as Glean server event

api/tests/phones_views_tests.py

@@ -1,3 +1,4 @@
+import json
 import re
 from collections.abc import Iterator
 from dataclasses import dataclass
@@ -17,6 +18,8 @@
 from twilio.rest import Client
 from waffle.testutils import override_flag
 
+from privaterelay.tests.glean_tests import assert_glean_record
+
 if settings.PHONES_ENABLED:
     from api.views.phones import MatchByPrefix, _match_by_prefix
     from phones.models import InboundContact, RealPhone, RelayNumber
@@ -867,7 +870,9 @@ def test_inbound_sms_valid_twilio_signature_good_data_deactivated_user(
     assert relay_number.remaining_texts == pre_inbound_remaining_texts
 
 
-def test_inbound_sms_valid_twilio_signature_good_data(phone_user, mocked_twilio_client):
+def test_inbound_sms_valid_twilio_signature_good_data(
+    phone_user, mocked_twilio_client, caplog
+):
     real_phone = _make_real_phone(phone_user, verified=True)
     relay_number = _make_relay_number(phone_user)
     pre_inbound_remaining_texts = relay_number.remaining_texts
@@ -876,7 +881,9 @@ def test_inbound_sms_valid_twilio_signature_good_data(phone_user, mocked_twilio_
     client = APIClient()
     path = "/api/v1/inbound_sms"
     data = {"From": "+15556660000", "To": relay_number.number, "Body": "test body"}
-    response = client.post(path, data, HTTP_X_TWILIO_SIGNATURE="valid")
+
+    with caplog.at_level("INFO"):
+        response = client.post(path, data, HTTP_X_TWILIO_SIGNATURE="valid")
 
     assert response.status_code == 201
     mocked_twilio_client.messages.create.assert_called_once()
@@ -888,6 +895,15 @@ def test_inbound_sms_valid_twilio_signature_good_data(phone_user, mocked_twilio_
     assert relay_number.texts_forwarded == 1
     assert relay_number.remaining_texts == pre_inbound_remaining_texts - 1
 
+    for record in caplog.records:
+        if record.name == "glean-server-event":
+            assert_glean_record(record)
+            payload = json.loads(getattr(record, "payload"))
+            event = payload["events"][0]
+            assert event["category"] == "phone"
+            assert event["name"] == "text_received"
+            assert event["extra"]["fxa_id"] == phone_user.profile.metrics_fxa_id
+
 
 def test_inbound_sms_valid_twilio_signature_disabled_number(
     phone_user, mocked_twilio_client
@@ -2092,7 +2108,7 @@ def test_inbound_call_valid_twilio_signature_good_data_deactivated_user(
 
 
 def test_inbound_call_valid_twilio_signature_good_data(
-    phone_user, mocked_twilio_client
+    phone_user, mocked_twilio_client, caplog
 ):
     real_phone = _make_real_phone(phone_user, verified=True)
     relay_number = _make_relay_number(phone_user, enabled=True)
@@ -2103,7 +2119,8 @@ def test_inbound_call_valid_twilio_signature_good_data(
     client = APIClient()
     path = "/api/v1/inbound_call"
     data = {"Caller": caller_number, "Called": relay_number.number}
-    response = client.post(path, data, HTTP_X_TWILIO_SIGNATURE="valid")
+    with caplog.at_level("INFO"):
+        response = client.post(path, data, HTTP_X_TWILIO_SIGNATURE="valid")
 
     assert response.status_code == 201
     decoded_content = response.content.decode()
@@ -2117,6 +2134,15 @@ def test_inbound_call_valid_twilio_signature_good_data(
     assert inbound_contact.num_calls == 1
     assert inbound_contact.last_inbound_type == "call"
 
+    for record in caplog.records:
+        if record.name == "glean-server-event":
+            assert_glean_record(record)
+            payload = json.loads(getattr(record, "payload"))
+            event = payload["events"][0]
+            assert event["category"] == "phone"
+            assert event["name"] == "call_received"
+            assert event["extra"]["fxa_id"] == phone_user.profile.metrics_fxa_id
+
 
 def test_inbound_call_valid_twilio_signature_disabled_number(
     phone_user, mocked_twilio_client

api/views/phones.py

@@ -62,6 +62,7 @@
     suggested_numbers,
 )
 from privaterelay.ftl_bundles import main as ftl_bundle
+from privaterelay.utils import glean_logger
 
 from ..exceptions import ConflictError
 from ..permissions import HasPhoneService
@@ -721,6 +722,7 @@ def inbound_sms(request):
             template_name="twiml_empty_response.xml",
         )
 
+    glean_logger().log_text_received(user=real_phone.user)
     _check_remaining(relay_number, "texts")
 
     if inbound_from == real_phone.number:
@@ -1004,6 +1006,7 @@ def inbound_call(request):
             template_name="twiml_empty_response.xml",
         )
 
+    glean_logger().log_call_received(user=real_phone.user)
     number_disabled = _check_disabled(relay_number, "calls")
     if number_disabled:
         say = "Sorry, that number is not available."

privaterelay/glean/server_events.py

@@ -90,6 +90,37 @@ def emit_record(self, now: datetime, ping: dict[str, Any]) -> None:
 
         print(ping_envelope_serialized)
 
+    def record_api_accessed(
+        self,
+        user_agent: str,
+        ip_address: str,
+        endpoint: str,
+        method: str,
+        fxa_id: str,
+    ) -> None:
+        """
+        Record and submit a api_accessed event:
+        An API endpoint was accessed.
+        Event is logged to STDOUT via `print`.
+
+        :param str user_agent: The user agent.
+        :param str ip_address: The IP address. Will be used to decode Geo information
+            and scrubbed at ingestion.
+        :param str endpoint: The name of the endpoint accessed
+        :param str method: HTTP method used
+        :param str fxa_id: Mozilla accounts user ID
+        """
+        event = {
+            "category": "api",
+            "name": "accessed",
+            "extra": {
+                "endpoint": str(endpoint),
+                "method": str(method),
+                "fxa_id": str(fxa_id),
+            },
+        }
+        self._record(user_agent, ip_address, event)
+
     def record_email_blocked(
         self,
         user_agent: str,
@@ -395,6 +426,56 @@ def record_email_mask_label_updated(
         }
         self._record(user_agent, ip_address, event)
 
+    def record_phone_call_received(
+        self,
+        user_agent: str,
+        ip_address: str,
+        fxa_id: str,
+    ) -> None:
+        """
+        Record and submit a phone_call_received event:
+        A Relay user receives a phone call.
+        Event is logged to STDOUT via `print`.
+
+        :param str user_agent: The user agent.
+        :param str ip_address: The IP address. Will be used to decode Geo information
+            and scrubbed at ingestion.
+        :param str fxa_id: Mozilla accounts user ID
+        """
+        event = {
+            "category": "phone",
+            "name": "call_received",
+            "extra": {
+                "fxa_id": str(fxa_id),
+            },
+        }
+        self._record(user_agent, ip_address, event)
+
+    def record_phone_text_received(
+        self,
+        user_agent: str,
+        ip_address: str,
+        fxa_id: str,
+    ) -> None:
+        """
+        Record and submit a phone_text_received event:
+        A Relay user receives a text message.
+        Event is logged to STDOUT via `print`.
+
+        :param str user_agent: The user agent.
+        :param str ip_address: The IP address. Will be used to decode Geo information
+            and scrubbed at ingestion.
+        :param str fxa_id: Mozilla accounts user ID
+        """
+        event = {
+            "category": "phone",
+            "name": "text_received",
+            "extra": {
+                "fxa_id": str(fxa_id),
+            },
+        }
+        self._record(user_agent, ip_address, event)
+
 
 def create_events_server_event_logger(
     application_id: str,

privaterelay/glean_interface.py

@@ -298,3 +298,49 @@ def log_email_blocked(
             is_reply=is_reply,
             reason=reason,
         )
+
+    def log_api_accessed(self, request: HttpRequest) -> None:
+        """Log that any Relay API endpoint was accessed."""
+        if not request.user or not request.user.is_authenticated:
+            return
+        request_data = RequestData.from_request(request)
+        user_data = UserData.from_user(request.user)
+        self.record_api_accessed(
+            user_agent=_opt_str_to_glean(request_data.user_agent),
+            ip_address=_opt_str_to_glean(request_data.ip_address),
+            endpoint=request.path,
+            method=_opt_str_to_glean(request.method),
+            fxa_id=_opt_str_to_glean(user_data.fxa_id),
+        )
+
+    def log_text_received(
+        self,
+        *,
+        user: User,
+    ) -> None:
+        """Log that a text message was received."""
+        user_data = UserData.from_user(user)
+        if not user_data.metrics_enabled:
+            return
+        request_data = RequestData()
+        self.record_phone_text_received(
+            user_agent=_opt_str_to_glean(request_data.user_agent),
+            ip_address=_opt_str_to_glean(request_data.ip_address),
+            fxa_id=_opt_str_to_glean(user_data.fxa_id),
+        )
+
+    def log_call_received(
+        self,
+        *,
+        user: User,
+    ) -> None:
+        """Log that a phone call was received."""
+        user_data = UserData.from_user(user)
+        if not user_data.metrics_enabled:
+            return
+        request_data = RequestData()
+        self.record_phone_call_received(
+            user_agent=_opt_str_to_glean(request_data.user_agent),
+            ip_address=_opt_str_to_glean(request_data.ip_address),
+            fxa_id=_opt_str_to_glean(user_data.fxa_id),
+        )

privaterelay/middleware.py

@@ -13,6 +13,8 @@
 from csp.middleware import CSPMiddleware
 from whitenoise.middleware import WhiteNoiseMiddleware
 
+from privaterelay.utils import glean_logger
+
 metrics = markus.get_metrics()
 
 
@@ -197,3 +199,13 @@ def is_staticfile(self, path_info: str) -> bool:
         else:
             static_file = self.files.get(path_info)
         return static_file is not None
+
+
+class GleanApiAccessMiddleware:
+    def __init__(self, get_response):
+        self.get_response = get_response
+
+    def __call__(self, request):
+        if request.path.startswith("/api/"):
+            glean_logger().log_api_accessed(request)
+        return self.get_response(request)

privaterelay/settings.py

@@ -395,6 +395,7 @@
     "waffle.middleware.WaffleMiddleware",
     "privaterelay.middleware.AddDetectedCountryToRequestAndResponseHeaders",
     "privaterelay.middleware.StoreFirstVisit",
+    "privaterelay.middleware.GleanApiAccessMiddleware",
 ]
 
 ROOT_URLCONF = "privaterelay.urls"

privaterelay/tests/glean_tests.py

@@ -552,3 +552,73 @@ def test_log_email_blocked_with_opt_out(
 
     # Check the one glean-server-event log
     assert len(caplog.records) == 0
+
+
+@pytest.mark.django_db
+def test_log_api_accessed(
+    glean_logger: RelayGleanLogger,
+    caplog: pytest.LogCaptureFixture,
+    rf: RequestFactory,
+) -> None:
+    """Check that log_api_accessed emits a Glean server-side log."""
+    user_agent = "RelayBot/0.9"
+    path = "/api/v1/profiles/"
+    request = rf.get(path, HTTP_USER_AGENT=user_agent)
+    user = make_free_test_user()
+    request.user = user
+
+    glean_logger.log_api_accessed(request)
+
+    # Check the one glean-server-event log
+    assert len(caplog.records) == 1
+    record = caplog.records[0]
+    assert_glean_record(record, user_agent=user_agent)
+
+    # Check payload structure
+    payload = json.loads(getattr(record, "payload"))
+    payload_event = payload["events"][0]
+    assert payload_event["category"] == "api"
+    assert payload_event["name"] == "accessed"
+    assert payload_event["extra"]["endpoint"] == path
+    assert payload_event["extra"]["method"] == "GET"
+    assert payload_event["extra"]["fxa_id"] == user.profile.metrics_fxa_id
+
+
+@pytest.mark.django_db
+def test_log_text_received(
+    glean_logger: RelayGleanLogger,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """Check that log_text_received emits a Glean server-side log."""
+    user = make_free_test_user()
+    with caplog.at_level("INFO"):
+        glean_logger.log_text_received(user=user)
+
+    assert len(caplog.records) == 1
+    record = caplog.records[0]
+    assert_glean_record(record)
+    payload = json.loads(getattr(record, "payload"))
+    event = payload["events"][0]
+    assert event["category"] == "phone"
+    assert event["name"] == "text_received"
+    assert event["extra"]["fxa_id"] == user.profile.metrics_fxa_id
+
+
+@pytest.mark.django_db
+def test_log_call_received(
+    glean_logger: RelayGleanLogger,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """Check that log_call_received emits a Glean server-side log."""
+    user = make_free_test_user()
+    with caplog.at_level("INFO"):
+        glean_logger.log_call_received(user=user)
+
+    assert len(caplog.records) == 1
+    record = caplog.records[0]
+    assert_glean_record(record)
+    payload = json.loads(getattr(record, "payload"))
+    event = payload["events"][0]
+    assert event["category"] == "phone"
+    assert event["name"] == "call_received"
+    assert event["extra"]["fxa_id"] == user.profile.metrics_fxa_id