Track login token reuse in a Prometheus metric

synapse/handlers/auth.py

@@ -38,6 +38,7 @@
 import attr
 import bcrypt
 import unpaddedbase64
+from prometheus_client import Counter
 
 from twisted.internet.defer import CancelledError
 from twisted.web.server import Request
@@ -48,6 +49,7 @@
     Codes,
     InteractiveAuthIncompleteError,
     LoginError,
+    NotFoundError,
     StoreError,
     SynapseError,
     UserDeactivatedError,
@@ -63,7 +65,11 @@
 from synapse.http.site import SynapseRequest
 from synapse.logging.context import defer_to_thread
 from synapse.metrics.background_process_metrics import run_as_background_process
-from synapse.storage.databases.main.registration import LoginTokenLookupResult
+from synapse.storage.databases.main.registration import (
+    LoginTokenExpired,
+    LoginTokenLookupResult,
+    LoginTokenReused,
+)
 from synapse.types import JsonDict, Requester, UserID
 from synapse.util import stringutils as stringutils
 from synapse.util.async_helpers import delay_cancellation, maybe_awaitable
@@ -80,6 +86,12 @@
 
 INVALID_USERNAME_OR_PASSWORD = "Invalid username or password"
 
+invalid_login_token_counter = Counter(
+    "synapse_user_login_invalid_login_tokens",
+    "Counts the number of rejected m.login.token on /login",
+    ["reason"],
+)
+
 
 def convert_client_dict_legacy_fields_to_identifier(
     submission: JsonDict,
@@ -1459,11 +1471,16 @@ def generate_refresh_token(self, for_user: UserID) -> str:
         return f"{base}_{crc}"
 
     async def consume_login_token(self, login_token: str) -> LoginTokenLookupResult:
-        res = await self.store.consume_login_token(login_token)
-        if res is None:
-            raise AuthError(403, "Invalid login token", errcode=Codes.FORBIDDEN)
-
-        return res
+        try:
+            return await self.store.consume_login_token(login_token)
+        except LoginTokenExpired:
+            invalid_login_token_counter.labels("expired").inc()
+        except LoginTokenReused:
+            invalid_login_token_counter.labels("reused").inc()
+        except NotFoundError:
+            invalid_login_token_counter.labels("not found").inc()
+
+        raise AuthError(403, "Invalid login token", errcode=Codes.FORBIDDEN)
 
     async def delete_access_token(self, access_token: str) -> None:
         """Invalidate a single access token

synapse/storage/databases/main/registration.py

@@ -21,7 +21,13 @@
 import attr
 
 from synapse.api.constants import UserTypes
-from synapse.api.errors import Codes, StoreError, SynapseError, ThreepidValidationError
+from synapse.api.errors import (
+    Codes,
+    NotFoundError,
+    StoreError,
+    SynapseError,
+    ThreepidValidationError,
+)
 from synapse.config.homeserver import HomeServerConfig
 from synapse.metrics.background_process_metrics import wrap_as_background_process
 from synapse.storage.database import (
@@ -50,6 +56,14 @@ class ExternalIDReuseException(Exception):
     because this external id is given to an other user."""
 
 
+class LoginTokenExpired(Exception):
+    """Exception if the login token sent expired"""
+
+
+class LoginTokenReused(Exception):
+    """Exception if the login token sent was already used"""
+
+
 @attr.s(frozen=True, slots=True, auto_attribs=True)
 class TokenLookupResult:
     """Result of looking up an access token.
@@ -1840,61 +1854,51 @@ def _consume_login_token(
         txn: LoggingTransaction,
         token: str,
         ts: int,
-    ) -> Optional[LoginTokenLookupResult]:
-        if self.database_engine.supports_returning:
-            # If the database engine supports the `RETURNING` keyword, delete and fetch
-            # the token with one query
-            txn.execute(
-                """
-                DELETE FROM login_tokens
-                WHERE token = ?
-                RETURNING user_id, expiry_ts, auth_provider_id, auth_provider_session_id
-                """,
-                (token,),
-            )
-            ret = txn.fetchone()
-            if ret is None:
-                return None
+    ) -> LoginTokenLookupResult:
+        values = self.db_pool.simple_select_one_txn(
+            txn,
+            "login_tokens",
+            keyvalues={"token": token},
+            retcols=(
+                "user_id",
+                "expiry_ts",
+                "used_ts",
+                "auth_provider_id",
+                "auth_provider_session_id",
+            ),
+            allow_none=True,
+        )
 
-            user_id, expiry_ts, auth_provider_id, auth_provider_session_id = ret
-        else:
-            values = self.db_pool.simple_select_one_txn(
-                txn,
-                "login_tokens",
-                keyvalues={"token": token},
-                retcols=(
-                    "user_id",
-                    "expiry_ts",
-                    "auth_provider_id",
-                    "auth_provider_session_id",
-                ),
-                allow_none=True,
-            )
+        if values is None:
+            raise NotFoundError()
 
-            if values is None:
-                return None
+        self.db_pool.simple_update_one_txn(
+            txn,
+            "login_tokens",
+            keyvalues={"token": token},
+            updatevalues={"used_ts": ts},
+        )
+        user_id = values["user_id"]
+        expiry_ts = values["expiry_ts"]
+        used_ts = values["used_ts"]
+        auth_provider_id = values["auth_provider_id"]
+        auth_provider_session_id = values["auth_provider_session_id"]
 
-            self.db_pool.simple_delete_one_txn(
-                txn,
-                "login_tokens",
-                keyvalues={"token": token},
-            )
-            user_id = values["user_id"]
-            expiry_ts = values["expiry_ts"]
-            auth_provider_id = values["auth_provider_id"]
-            auth_provider_session_id = values["auth_provider_session_id"]
+        # Token was already used
+        if used_ts is not None:
+            raise LoginTokenReused()
 
         # Token expired
         if ts > int(expiry_ts):
-            return None
+            raise LoginTokenExpired()
 
         return LoginTokenLookupResult(
             user_id=user_id,
             auth_provider_id=auth_provider_id,
             auth_provider_session_id=auth_provider_session_id,
         )
 
-    async def consume_login_token(self, token: str) -> Optional[LoginTokenLookupResult]:
+    async def consume_login_token(self, token: str) -> LoginTokenLookupResult:
         """Lookup a login token and consume it.
 
         Args:
@@ -1903,6 +1907,11 @@ async def consume_login_token(self, token: str) -> Optional[LoginTokenLookupResu
         Returns:
             The data stored with that token, including the `user_id`. Returns `None` if
             the token does not exist or if it expired.
+
+        Raises:
+            NotFound if the login token was not found in database
+            LoginTokenExpired if the login token expired
+            LoginTokenReused if the login token was already used
         """
         return await self.db_pool.runInteraction(
             "consume_login_token",
@@ -2753,10 +2762,13 @@ def _delete_expired_login_tokens_txn(txn: LoggingTransaction, ts: int) -> None:
             sql = "DELETE FROM login_tokens WHERE expiry_ts <= ?"
             txn.execute(sql, (ts,))
 
+        # We keep the expired tokens for an extra 5 minutes so we can measure how many
+        # times a token is being used after its expiry
+        now = self._clock.time_msec()
         await self.db_pool.runInteraction(
             "delete_expired_login_tokens",
             _delete_expired_login_tokens_txn,
-            self._clock.time_msec(),
+            now - (5 * 60 * 1000),
         )
 
 

synapse/storage/schema/main/delta/73/10login_tokens.sql

@@ -20,6 +20,7 @@ CREATE TABLE login_tokens (
     token TEXT PRIMARY KEY,
     user_id TEXT NOT NULL, 
     expiry_ts BIGINT NOT NULL,
+    used_ts BIGINT,
     auth_provider_id TEXT,
     auth_provider_session_id TEXT
 );