Merge pull request #5824 from raft-tech/hotfix/security-event-token-email-changed-bug

Hotfix: SET Handler using `subject_type` instead of `new-value`

Author: elipe17

tdrs-backend/tdpservice/security/event_handler.py

@@ -59,19 +59,21 @@ def _get_emails(security_event):
         """Get the old and new emails from the event data."""
         event_data = security_event.event_data
         subject = event_data.get("subject")
-        new_email = subject.get("subject_type")
         old_email = subject.get("email")
+        new_email = event_data.get("new-value")
         return new_email, old_email
 
     def _handle_email_changed(security_event):
-        """Handle email-changed event."""
+        """Handle email-changed event without mutating the user record."""
         new_email, old_email = SecurityEventHandler._get_emails(security_event)
-
         user = security_event.user
-        user.email = new_email
-        user.username = new_email
-        user.save()
-        logger.info(f"User changed email from {old_email} to {new_email}")
+        logger.info(
+            "User %s identifier changed for email %s; SET new-value=%s. "
+            "User email is synced from OIDC claims on login.",
+            user.username,
+            old_email,
+            new_email,
+        )
 
     def _handle_email_recycled(security_event):
         """Handle email-recycled event."""
@@ -112,6 +114,56 @@ def _handle_reproof_complete(security_event):
         SecurityEventType.REPROOF_COMPLETE: _handle_reproof_complete,
     }
 
+    user_mutation_event_types = {
+        SecurityEventType.ACCOUNT_DISABLED,
+        SecurityEventType.ACCOUNT_ENABLED,
+        SecurityEventType.ACCOUNT_PURGED,
+    }
+
+    @classmethod
+    def _get_issued_at(cls, decoded_jwt):
+        """Convert the SET issued-at timestamp to a datetime."""
+        iat_timestamp = decoded_jwt.get("iat")
+        if not iat_timestamp:
+            return None
+
+        try:
+            return datetime.fromtimestamp(iat_timestamp, tz=dt_timezone.utc)
+        except (ValueError, TypeError) as e:
+            logger.warning(f"Error converting timestamp {iat_timestamp}: {e}")
+            return None
+
+    @classmethod
+    def _create_security_event(cls, user, event_type, event_data, decoded_jwt):
+        """Create a SecurityEventToken for a known or unmatched event subject."""
+        subject = event_data.get("subject", {})
+        return SecurityEventToken.objects.create(
+            user=user,
+            email=user.email if user else subject.get("email"),
+            event_type=event_type,
+            event_data=event_data,
+            jwt_id=decoded_jwt.get("jti"),
+            issuer=decoded_jwt.get("iss"),
+            issued_at=cls._get_issued_at(decoded_jwt),
+        )
+
+    @classmethod
+    def _mark_processed(cls, security_event):
+        """Mark a security event as processed."""
+        security_event.processed = True
+        security_event.processed_at = timezone.now()
+        security_event.save()
+
+    @classmethod
+    def _has_subject_identifier(cls, subject):
+        """Return whether the event subject contains an identifier we understand."""
+        return bool(subject.get("sub") or subject.get("email"))
+
+    @classmethod
+    def _event_mutates_user(cls, event_type):
+        """Return whether handling the event is allowed to update the user model."""
+        return event_type in cls.user_mutation_event_types
+
     @classmethod
     def _get_user(cls, subject):
         """Get User model from email or UUID."""
@@ -124,17 +176,17 @@ def _get_user(cls, subject):
                     "No user found with login_gov_uuid: {}".format(subject.get("sub"))
                 )
         elif "email" in subject:
-            # Check both emails in the subject to see if we have the user
-            user_qset = User.objects.filter(username=subject.get("email"))
-            if user_qset.exists() and user_qset.count() == 1:
-                return user_qset.first()
+            if subject.get("subject_type") != "email":
+                raise ValueError(
+                    "Email subject security event must have subject_type 'email'."
+                )
 
-            user_qset = User.objects.filter(username=subject.get("subject_type"))
+            user_qset = User.objects.filter(username=subject.get("email"))
             if user_qset.exists() and user_qset.count() == 1:
                 return user_qset.first()
 
             raise ValueError(
-                "No user found with the provided 'email' or 'subject_type' in subject of security event."
+                "No user found with the provided 'email' in subject of security event."
             )
 
         raise ValueError("No user info found in subject of security event.")
@@ -144,36 +196,36 @@ def handle_event(cls, event_type, event_data, decoded_jwt):
         """Handle specific event types."""
         try:
             subject = event_data.get("subject", {})
-            user = cls._get_user(subject)
-
-            # Convert Unix timestamp to datetime if present
-            iat_timestamp = decoded_jwt.get("iat")
-            issued_at = None
-            if iat_timestamp:
-                try:
-                    issued_at = datetime.fromtimestamp(
-                        iat_timestamp, tz=dt_timezone.utc
-                    )
-                except (ValueError, TypeError) as e:
-                    logger.warning(f"Error converting timestamp {iat_timestamp}: {e}")
-
-            security_event = SecurityEventToken.objects.create(
-                user=user,
-                email=user.email,
-                event_type=event_type,
-                event_data=event_data,
-                jwt_id=decoded_jwt.get("jti"),
-                issuer=decoded_jwt.get("iss"),
-                issued_at=issued_at,
+            try:
+                user = cls._get_user(subject)
+            except ValueError:
+                if cls._event_mutates_user(
+                    event_type
+                ) or not cls._has_subject_identifier(subject):
+                    raise
+
+                security_event = cls._create_security_event(
+                    None, event_type, event_data, decoded_jwt
+                )
+                cls._mark_processed(security_event)
+                logger.warning(
+                    "Recorded %s event with unmatched subject %s. "
+                    "No user mutation was applied; email is synced from OIDC "
+                    "claims on login.",
+                    event_type,
+                    subject,
+                )
+                return
+
+            security_event = cls._create_security_event(
+                user, event_type, event_data, decoded_jwt
             )
 
             # Call the appropriate handler
             handler = cls.handler_map.get(event_type, cls._handle_unknown_event)
             handler(security_event)
 
-            security_event.processed = True
-            security_event.processed_at = timezone.now()
-            security_event.save()
+            cls._mark_processed(security_event)
 
         except Exception as e:
             logger.exception(f"Error handling event {event_type}: {e}")

tdrs-backend/tdpservice/security/test/test_event_handler.py

@@ -49,17 +49,25 @@ def email_changed_event_data(stt_data_analyst):
     """Mock event data for email changed: includes old and new emails."""
     old_email = stt_data_analyst.email
     new_email = "new_email@example.com"
-    return {"subject": {"email": old_email, "subject_type": new_email}}
+    return {
+        "subject": {"email": old_email, "subject_type": "email"},
+        "new-value": new_email,
+    }
+
+
+@pytest.fixture
+def email_changed_event_data_without_new_value(stt_data_analyst):
+    """Mock Login.gov event data for email changed without a new email."""
+    return {"subject": {"email": stt_data_analyst.email, "subject_type": "email"}}
 
 
 @pytest.fixture
 def email_recycled_event_data(stt_data_analyst):
     """Mock event data for email recycled: includes the recycled email."""
-    # Only the old email is relevant for handler logging; use a placeholder for subject_type
     return {
         "subject": {
             "email": stt_data_analyst.email,
-            "subject_type": "unused@example.com",
+            "subject_type": "email",
         }
     }
 
@@ -222,6 +230,55 @@ def test_recovery_information_changed(
             decoded_jwt["iat"], tz=timezone.utc
         )
 
+    @pytest.mark.django_db
+    @pytest.mark.parametrize(
+        "event_type",
+        [
+            SecurityEventType.MFA_LOCKED,
+            SecurityEventType.EMAIL_CHANGED,
+            SecurityEventType.EMAIL_RECYCLED,
+            SecurityEventType.PASSWORD_RESET,
+            SecurityEventType.RECOVERY_ACTIVATED,
+            SecurityEventType.RECOVERY_INFORMATION_CHANGED,
+            SecurityEventType.REPROOF_COMPLETE,
+        ],
+    )
+    def test_non_mutating_events_do_not_update_user(
+        self, stt_data_analyst, event_type, decoded_jwt
+    ):
+        """Test only account status and purge events mutate the user model."""
+        prev_email = stt_data_analyst.email
+        prev_username = stt_data_analyst.username
+        prev_active = stt_data_analyst.is_active
+        prev_login_gov_uuid = str(stt_data_analyst.login_gov_uuid)
+        prev_status = stt_data_analyst.account_approval_status
+        event_data = {"subject": {"sub": str(stt_data_analyst.login_gov_uuid)}}
+
+        if event_type in {
+            SecurityEventType.EMAIL_CHANGED,
+            SecurityEventType.EMAIL_RECYCLED,
+        }:
+            event_data = {
+                "subject": {
+                    "email": stt_data_analyst.email,
+                    "subject_type": "email",
+                }
+            }
+
+        SecurityEventHandler.handle_event(event_type, event_data, decoded_jwt)
+
+        stt_data_analyst.refresh_from_db()
+
+        assert stt_data_analyst.email == prev_email
+        assert stt_data_analyst.username == prev_username
+        assert stt_data_analyst.is_active == prev_active
+        assert str(stt_data_analyst.login_gov_uuid) == prev_login_gov_uuid
+        assert stt_data_analyst.account_approval_status == prev_status
+
+        token = SecurityEventToken.objects.first()
+        assert token.processed is True
+        assert token.event_type == event_type
+
     @pytest.mark.django_db
     def test_mfa_locked(self, stt_data_analyst, event_data, decoded_jwt):
         """Test handling of mfa-locked event."""
@@ -254,17 +311,19 @@ def test_mfa_locked(self, stt_data_analyst, event_data, decoded_jwt):
     def test_email_changed(
         self, stt_data_analyst, email_changed_event_data, decoded_jwt
     ):
-        """Test handling email-changed event updates user's email and username."""
+        """Test handling email-changed event does not update user's email and username."""
+        prev_email = stt_data_analyst.email
+        prev_username = stt_data_analyst.username
+
         event_type = SecurityEventType.EMAIL_CHANGED
         SecurityEventHandler.handle_event(
             event_type, email_changed_event_data, decoded_jwt
         )
 
         stt_data_analyst.refresh_from_db()
 
-        new_email = email_changed_event_data["subject"]["subject_type"]
-        assert stt_data_analyst.email == new_email
-        assert stt_data_analyst.username == new_email
+        assert stt_data_analyst.email == prev_email
+        assert stt_data_analyst.username == prev_username
 
         assert SecurityEventToken.objects.count() == 1
         token = SecurityEventToken.objects.first()
@@ -278,6 +337,84 @@ def test_email_changed(
             decoded_jwt["iat"], tz=timezone.utc
         )
 
+    @pytest.mark.django_db
+    def test_email_changed_without_new_value_does_not_update_user(
+        self, stt_data_analyst, email_changed_event_data_without_new_value, decoded_jwt
+    ):
+        """Test Login.gov identifier-changed payload does not set email to subject_type."""
+        prev_email = stt_data_analyst.email
+        prev_username = stt_data_analyst.username
+
+        event_type = SecurityEventType.EMAIL_CHANGED
+        SecurityEventHandler.handle_event(
+            event_type, email_changed_event_data_without_new_value, decoded_jwt
+        )
+
+        stt_data_analyst.refresh_from_db()
+
+        assert stt_data_analyst.email == prev_email
+        assert stt_data_analyst.username == prev_username
+
+        assert SecurityEventToken.objects.count() == 1
+        token = SecurityEventToken.objects.first()
+        assert token.user == stt_data_analyst
+        assert token.processed is True
+        assert token.event_type == event_type
+        assert token.event_data == email_changed_event_data_without_new_value
+
+    @pytest.mark.django_db
+    def test_email_changed_for_unknown_email_records_processed_event(
+        self, caplog, decoded_jwt
+    ):
+        """Test Login.gov identifier-changed can arrive with a new unknown email."""
+        event_type = SecurityEventType.EMAIL_CHANGED
+        event_data = {
+            "subject": {
+                "email": "new_login_email@example.com",
+                "subject_type": "email",
+            }
+        }
+
+        with caplog.at_level(logging.WARNING):
+            SecurityEventHandler.handle_event(event_type, event_data, decoded_jwt)
+
+        assert "No user found with the provided 'email'" not in caplog.text
+        assert "unmatched subject" in caplog.text
+
+        assert SecurityEventToken.objects.count() == 1
+        token = SecurityEventToken.objects.first()
+        assert token.user is None
+        assert token.email == "new_login_email@example.com"
+        assert token.processed is True
+        assert token.processed_at is not None
+        assert token.event_type == event_type
+        assert token.event_data == event_data
+        assert token.jwt_id == decoded_jwt["jti"]
+        assert token.issuer == decoded_jwt["iss"]
+
+    @pytest.mark.django_db
+    def test_non_mutating_event_for_unknown_sub_records_processed_event(
+        self, caplog, decoded_jwt
+    ):
+        """Test non-mutating events with an unknown sub are recorded for audit."""
+        event_type = SecurityEventType.PASSWORD_RESET
+        event_data = {"subject": {"sub": str(uuid.uuid4())}}
+
+        with caplog.at_level(logging.WARNING):
+            SecurityEventHandler.handle_event(event_type, event_data, decoded_jwt)
+
+        assert "No user found with login_gov_uuid" not in caplog.text
+        assert "unmatched subject" in caplog.text
+
+        assert SecurityEventToken.objects.count() == 1
+        token = SecurityEventToken.objects.first()
+        assert token.user is None
+        assert token.email is None
+        assert token.processed is True
+        assert token.processed_at is not None
+        assert token.event_type == event_type
+        assert token.event_data == event_data
+
     @pytest.mark.django_db
     def test_email_recycled(
         self, stt_data_analyst, email_recycled_event_data, decoded_jwt
@@ -351,9 +488,9 @@ def test_handle_event_no_sub(self, caplog):
 
     @pytest.mark.django_db
     def test_handle_event_user_not_found(self, caplog):
-        """Test handling event when user is not found."""
+        """Test handling user-mutating event when user is not found."""
 
-        event_type = SecurityEventType.UNKNOWN_EVENT
+        event_type = SecurityEventType.ACCOUNT_DISABLED
         login_gov_uuid = uuid.uuid4()
         event_data = {"subject": {"sub": str(login_gov_uuid)}}
         decoded_jwt = {}