Trust proxy headers by hop count, and log every credential event

Operator, before exposing the instance: *"I'd expect that we should have a proxy
hops setting for how many proxy hops we should trust a shared real-ip at… and is
there any session logging."* Neither existed, and the first one was a real hole.

**The address was forgeable.** `client_address()` read the LEFTMOST
`X-Forwarded-For` entry — nominally "the original client", and precisely the one a
caller controls, because anything they send arrives before what proxies append. So
`curl -H "X-Forwarded-For: 1.2.3.4"`, rotated per request, minted a fresh
rate-limit bucket every time.

Concretely: stuffing ONE account stayed limited (the account key is unforgeable
and that is why it exists), but spraying MANY accounts from one source was not —
each account got its own budget, and the per-address cap meant to bound the total
was defeated by a header. On a LAN that is nothing. It is not nothing on a public
host.

Now it counts in from the RIGHT by `THOUGHTSYNC_TRUSTED_PROXY_HOPS`, default 1.
Each hop appends what it saw, so the rightmost entries are the ones our own
infrastructure wrote and a forged prefix lands to the left of them where it can
never be selected — proven for the honest, forged, padded, CDN and
shorter-than-configured cases. 0 ignores the header entirely; 2 is Cloudflare in
front of a proxy. Too high is the dangerous direction, so a header shorter than
configured falls back to the socket address rather than reaching further left.

`X-Forwarded-Proto` had the same bug and now shares the same rule. Both live in a
new `proxy.py` rather than being written twice — two places holding one decision
is how issue 2183 happened, and this is the same decision.

Env rather than the Settings UI, against rule 25's usual pull: it is deployment
topology rather than preference, and the limiter consults it BEFORE opening a
database connection, which is the entire point of checking a throttle before doing
expensive work. Easy to move if that reads wrong.

**And there was no logging at all** — `auth.py` had no logger, and the only record
of anything was `device_tokens.last_used_at`. Sign-ins, failures, throttle trips,
new accounts and device-token issuance now all log, with the attempted email and
the trusted address. Deliberately including the email: it is the operator's own
server, and "somebody failed a login" without saying against which account is not
actionable.

`basicConfig` at INFO in `create_app`, because hypercorn configures its own loggers
and leaves the root at WARNING — without it every line above would have gone
nowhere, which is a worse failure than not writing them.

This is the app log, not an audit table. Not queryable, not retained past log
rotation. The table is task 2939; this is what makes the next few days observable.

src/thoughtsync/app.py

@@ -1,13 +1,14 @@
 from __future__ import annotations
 
 import asyncio
+import logging
 import mimetypes
 import os
 import secrets
 from contextlib import suppress
 from datetime import timedelta
 
-from quart import Quart, has_request_context, jsonify, request, send_from_directory
+from quart import Quart, jsonify, send_from_directory
 from quart.sessions import SecureCookieSessionInterface
 
 from . import __version__
@@ -17,12 +18,25 @@ from .config import Config
 from .db import session_scope
 from .labels import bp as labels_bp
 from .notes import bp as notes_bp
+from .proxy import is_https
 from .retention import run_sweeper
 from .saved_filters import bp as saved_filters_bp
 from .settings import get_public_config, get_setting, load_or_create_secret_key
 from .settings_api import bp as settings_bp
 from .sync import bp as sync_bp, protocol_advertisement
 
+# Without this, `logger.info` from this package goes nowhere: hypercorn configures its
+# own access/error loggers and leaves the root logger at WARNING, so the credential
+# events in auth.py would be invisible in `docker compose logs` — which is exactly
+# where they are meant to be read until an audit table exists (task 2939).
+#
+# `force=False` (the default) so a host that has already configured logging keeps its
+# own setup; LOG_LEVEL lets an operator turn it up without a code change.
+logging.basicConfig(
+    level=os.environ.get("THOUGHTSYNC_LOG_LEVEL", "INFO").upper(),
+    format="%(asctime)s %(levelname)s %(name)s %(message)s",
+)
+
 STATIC_DIR = os.path.join(os.path.dirname(__file__), "static")
 
 # `.webmanifest` isn't in every base image's mime map; register it so the PWA
@@ -30,19 +44,6 @@ STATIC_DIR = os.path.join(os.path.dirname(__file__), "static")
 mimetypes.add_type("application/manifest+json", ".webmanifest")
 
 
-def _is_https() -> bool:
-    """Whether this request reached us over TLS — directly, or through a proxy that
-    terminated it and said so in X-Forwarded-Proto.
-
-    Shared by the session cookie's Secure flag and by HSTS, because they are the same
-    question and answering it twice is how the two drift apart.
-    """
-    if not has_request_context():
-        return False
-    forwarded = request.headers.get("X-Forwarded-Proto", "").split(",")[0].strip().lower()
-    return forwarded == "https" or request.is_secure
-
-
 class _AutoSecureSessionInterface(SecureCookieSessionInterface):
     """Mark the session cookie `Secure` whenever the request arrived over HTTPS —
     directly, or via a TLS-terminating reverse proxy that sets X-Forwarded-Proto.
@@ -54,7 +55,7 @@ class _AutoSecureSessionInterface(SecureCookieSessionInterface):
     """
 
     def get_cookie_secure(self, app: Quart) -> bool:
-        return _is_https()
+        return is_https()
 
 
 def create_app() -> Quart:
@@ -168,7 +169,7 @@ def create_app() -> Quart:
         # commit domains this app does not own. A browser still remembers the policy
         # for up to a year after the header stops being sent, which is the point of
         # it — worth knowing before putting a hostname behind TLS temporarily.
-        if _is_https():
+        if is_https():
             response.headers.setdefault("Strict-Transport-Security", "max-age=31536000")
         return response
 

src/thoughtsync/auth.py

@@ -1,6 +1,7 @@
 from __future__ import annotations
 
 import functools
+import logging
 import uuid
 from datetime import datetime, timezone
 
@@ -11,8 +12,8 @@ from .common import iso
 from .db import session_scope
 from .models.device_token import DeviceToken
 from .models.user import User
+from .proxy import client_address
 from .ratelimit import (
-    client_address,
     register_by_address,
     sign_in_by_account,
     sign_in_by_address,
@@ -22,6 +23,16 @@ from .settings import get_setting, set_settings
 
 bp = Blueprint("auth", __name__, url_prefix="/api/auth")
 
+# Every credential event goes to the app log — there is no audit TABLE yet (see task
+# 2939), and until there is, `docker compose logs` is the only way to know whether
+# anyone is knocking. That matters most in exactly the window this was written for: a
+# freshly-exposed instance.
+#
+# The attempted email is included deliberately. It is the operator's own server, and
+# "somebody failed a login" without saying against WHICH account tells you nothing you
+# can act on. Passwords, obviously, never appear.
+logger = logging.getLogger(__name__)
+
 SESSION_KEY = "user_id"
 MIN_PASSWORD_LEN = 8
 DEVICE_NAME_CAP = 100
@@ -120,6 +131,7 @@ def _throttled(retry_after: int):
     `Retry-After` is standard and is the one thing a legitimate client (or person)
     genuinely needs.
     """
+    logger.warning("throttled credential attempt from=%s retry_after=%ss", client_address(), retry_after)
     return (
         jsonify({"error": "too many attempts — try again shortly"}),
         429,
@@ -186,6 +198,7 @@ async def register():
         # The first account bootstraps the admin and is always allowed, even when
         # registration is otherwise closed.
         if not is_first and not await get_setting(db, "allow_registration"):
+            logger.warning("registration refused (closed) email=%s from=%s", email, client_address())
             return jsonify({"error": "registration is closed"}), 403
         existing = await db.scalar(select(User).where(User.email == email))
         if existing is not None:
@@ -215,6 +228,9 @@ async def register():
         await db.refresh(user)
         session[SESSION_KEY] = str(user.id)
         session.permanent = True
+        logger.info(
+            "account created email=%s admin=%s from=%s", email, is_first, client_address()
+        )
         return jsonify(_serialize_user(user)), 201
 
 
@@ -236,13 +252,16 @@ async def login():
             # difference is a reliable oracle for which emails have accounts here.
             dummy_verify(password)
             _sign_in_failed(email)
+            logger.warning("sign-in failed (no such account) email=%s from=%s", email, client_address())
             return jsonify({"error": "invalid email or password"}), 401
         if not verify_password(password, user.password_hash):
             _sign_in_failed(email)
+            logger.warning("sign-in failed (bad password) email=%s from=%s", email, client_address())
             return jsonify({"error": "invalid email or password"}), 401
         _sign_in_succeeded(email)
         session[SESSION_KEY] = str(user.id)
         session.permanent = True
+        logger.info("sign-in ok email=%s from=%s", email, client_address())
         return jsonify(_serialize_user(user))
 
 
@@ -310,12 +329,19 @@ async def device_login():
         if user is None or not user.password_hash:
             dummy_verify(password)
             _sign_in_failed(email)
+            logger.warning("device-login failed (no such account) email=%s from=%s", email, client_address())
             return jsonify({"error": "invalid email or password"}), 401
         if not verify_password(password, user.password_hash):
             _sign_in_failed(email)
+            logger.warning("device-login failed (bad password) email=%s from=%s", email, client_address())
             return jsonify({"error": "invalid email or password"}), 401
         _sign_in_succeeded(email)
         row, token = await _issue_device_token(db, user.id, data.get("name") or "")
+        # A device token outlives the session that made it, so its creation is the
+        # most consequential thing on this blueprint.
+        logger.info(
+            "device token issued email=%s device=%s from=%s", email, row.name, client_address()
+        )
         await db.commit()
         return jsonify({"token": token, "device": _serialize_device(row), "user": _serialize_user(user)}), 201
 

src/thoughtsync/config.py

@@ -15,6 +15,9 @@ class Config:
       If unset, a key is generated and persisted in the DB (see
       ``thoughtsync.settings.load_or_create_secret_key``), so sessions survive
       restarts with no volume required.
+    - ``THOUGHTSYNC_TRUSTED_PROXY_HOPS`` — how many proxies in front of this app may
+      be believed when reading ``X-Forwarded-For`` / ``X-Forwarded-Proto``. Defaults
+      to 1 (one reverse proxy terminating TLS). See ``trusted_proxy_hops``.
 
     Uploaded media lives under ``DATA_DIR`` — a fixed, authoritative path
     (``/var/thoughtsync``), intentionally NOT configurable (a mutable data path only
@@ -48,3 +51,36 @@ class Config:
     def secret_key_env(cls) -> str | None:
         """Optional break-glass override for the cookie-signing secret."""
         return os.environ.get("THOUGHTSYNC_SECRET_KEY") or None
+
+    @classmethod
+    def trusted_proxy_hops(cls) -> int:
+        """How many proxies in front of this app may be believed.
+
+        `X-Forwarded-For` grows LEFT to RIGHT: each hop appends the address it saw.
+        So the RIGHTMOST entry was written by our own proxy and is the address that
+        actually connected to it, while anything a client sent arrives to the LEFT of
+        that — which is why the leftmost entry, the "original client", is precisely
+        the one a caller can forge.
+
+        With `n` trusted hops the real client is the nth entry from the right:
+
+          0  no proxy — ignore the header entirely, use the socket address
+          1  one reverse proxy terminating TLS (the default, and this deployment)
+          2  a CDN in front of that proxy — Cloudflare appended the client, our
+             proxy appended Cloudflare
+
+        Set it to the number of proxies you actually run. Too HIGH and a caller can
+        forge an address by padding the header; too low and everyone behind the CDN
+        shares one bucket. Too low is the safe direction, so it is the fallback when
+        the header is shorter than configured.
+
+        Env rather than the Settings UI (rule 25's "absolute bootstrap only" carve-
+        out): it is a property of the deployment topology, not a preference, and the
+        rate limiter consults it before opening a database connection — which is the
+        whole point of checking a throttle before doing expensive work.
+        """
+        raw = os.environ.get("THOUGHTSYNC_TRUSTED_PROXY_HOPS", "1")
+        try:
+            return max(0, int(raw))
+        except (TypeError, ValueError):
+            return 1

src/thoughtsync/proxy.py

@@ -0,0 +1,74 @@
+"""Reading what the proxies in front of this app say about a request.
+
+Two headers carry information the app cannot see for itself — who the client is
+(`X-Forwarded-For`) and whether they arrived over TLS (`X-Forwarded-Proto`) — and both
+are trusted by the same rule, so the rule lives in one place. Writing it twice is
+precisely how issue 2183 happened: two places holding one decision, and only one of
+them updated.
+
+## The rule
+
+A forwarding header grows LEFT to RIGHT. Each hop appends what IT saw, so the
+rightmost entries are the ones our own infrastructure wrote, and anything a caller
+sent arrives to the LEFT of those.
+
+That inverts the intuitive reading. The leftmost entry is nominally "the original
+client" — and is exactly the one a caller can forge, by sending the header themselves.
+So we count in from the right by the number of proxies we actually run
+(`THOUGHTSYNC_TRUSTED_PROXY_HOPS`, default 1), and a forged prefix can never be
+selected no matter how much of it there is.
+
+Too HIGH a hop count is the dangerous direction: it starts believing entries no proxy
+of ours wrote. Too low just means several callers share a bucket. So when the header
+is shorter than configured — fewer proxies than expected — we fall back to the socket
+address rather than reaching further left.
+"""
+from __future__ import annotations
+
+from quart import has_request_context, request
+
+from .config import Config
+
+
+def trusted_entry(header: str, hops: int) -> str | None:
+    """The nth-from-the-right entry of a forwarding header, or None if there isn't one.
+
+    Pure, so the trust boundary is testable without a request context.
+    """
+    if hops <= 0:
+        return None
+    entries = [part.strip() for part in header.split(",") if part.strip()]
+    if len(entries) < hops:
+        return None
+    return entries[-hops]
+
+
+def forwarded_for(header: str, remote_addr: str | None, hops: int) -> str:
+    """The client address a proxy chain vouches for, else this connection's peer."""
+    entry = trusted_entry(header, hops)
+    return (entry or remote_addr or "unknown")[:64]  # bounded: becomes a dict key
+
+
+def client_address() -> str:
+    """The caller's address, as far as the deployment's own proxies vouch for it."""
+    return forwarded_for(
+        request.headers.get("X-Forwarded-For", ""),
+        request.remote_addr,
+        Config.trusted_proxy_hops(),
+    )
+
+
+def is_https() -> bool:
+    """Whether this request reached us over TLS — directly, or via a trusted proxy.
+
+    Shared by the session cookie's `Secure` flag and by HSTS, because they are the same
+    question. Read with the same hop count as the address: a caller who sets
+    `X-Forwarded-Proto: https` on a plain-HTTP request puts it to the left of whatever
+    our proxy appended, so it is not what gets read.
+    """
+    if not has_request_context():
+        return False
+    if request.is_secure:
+        return True
+    entry = trusted_entry(request.headers.get("X-Forwarded-Proto", ""), Config.trusted_proxy_hops())
+    return (entry or "").lower() == "https"

src/thoughtsync/ratelimit.py

@@ -22,9 +22,11 @@ came from, and either one can refuse it:
   is what stops credential stuffing against one known email, no matter how many
   addresses the attempts arrive from.
 - **The address** bounds the damage from one source spraying many accounts. It is
-  best-effort by nature — behind a reverse proxy the client address is read from
-  ``X-Forwarded-For``, which a caller can set to anything if the app is exposed
-  directly. That is precisely why it is not the only key.
+  read from ``X-Forwarded-For``, counting in from the RIGHT by
+  ``THOUGHTSYNC_TRUSTED_PROXY_HOPS`` so that only entries our own proxies wrote are
+  believed — a forged header lands to the left of those and is never selected. It is
+  still the weaker of the two keys, because it depends on that setting matching the
+  deployment; the account key depends on nothing.
 
 Counting is by failure for the sign-in routes and by attempt for registration: a
 correct password should never move someone closer to being locked out, but every
@@ -35,7 +37,6 @@ from __future__ import annotations
 import time
 from collections import deque
 
-from quart import request
 
 # Failed sign-ins tolerated per account before it stops answering, and for how long.
 # Ten is comfortably above a person mistyping a password and far below anything that
@@ -116,24 +117,6 @@ sign_in_by_address = SlidingWindow(ADDRESS_LIMIT, ADDRESS_WINDOW_S)
 register_by_address = SlidingWindow(REGISTER_LIMIT, REGISTER_WINDOW_S)
 
 
-def client_address() -> str:
-    """The caller's address, as well as it can be known.
-
-    ``X-Forwarded-For`` is a list appended to by each hop, so the leftmost entry is
-    the original client — and also the only entry a client can choose for itself.
-    It is trusted here anyway, because the alternative behind a reverse proxy is to
-    see the proxy's address for every request on earth and rate-limit the entire
-    internet as one caller. The account-keyed limit is the one that holds when this
-    one is lied to.
-    """
-    forwarded = request.headers.get("X-Forwarded-For", "")
-    if forwarded:
-        first = forwarded.split(",")[0].strip()
-        if first:
-            return first[:64]  # bounded: this becomes a dict key
-    return (request.remote_addr or "unknown")[:64]
-
-
 def reset_all() -> None:
     """Drop every counter. For tests — nothing in the app calls this."""
     for window in (sign_in_by_account, sign_in_by_address, register_by_address):