diff --git a/CLAUDE.md b/CLAUDE.md index f4e9c74..223f914 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -124,7 +124,7 @@ To send a Slack DM, pass the Slack user ID as `channel`: `send_slack(message=... These are DIFFERENT VALUES. When bundling user data for the frontend, include both: `{user_id: propel_id, db_id: firestore_doc_id, name, profile_image}`. The frontend needs `db_id` to build profile links and `user_id` (propel) for matching against assignees/editors/mentions. ## Volunteer time tracking (`/api/users/volunteering`) -GET/POST in `api/users/users_views.py` → `services/users_service.py`. Both resolve identity through `_resolve_and_ensure_user(propel_id)`, which **lazily creates the `users` doc when missing** (the lazy-creation gotcha). Before this, a user who'd authenticated but never opened their profile had no doc, so `fetch_user_by_user_id` → None → 404 on BOTH read and write — surfaced on the frontend as "Failed to load your volunteer data" and blocked them from starting a session ("not working for some people"). `get_volunteering_time` now returns `([], 0, 0)` (never None/404) so the page shows a clean zero-state, and filters in a SINGLE pass — an entry may carry `commitmentHours`, `finalHours`, or BOTH (manual logs send both), no concat/duplicate. `save_volunteering_time` accepts an optional `timestamp` (backdated manual logs) + `manual:true` flag; hours are float-cleaned, non-negative, capped at 1000. +GET/POST in `api/users/users_views.py` → `services/users_service.py`. Both resolve identity through `_resolve_and_ensure_user(propel_id)`, in this order so a broken OAuth provider token can NEVER block volunteering: **(1) `fetch_user_by_propel_id(propel_id)` — direct Firestore lookup on the stored `propel_id` field, NO external call (covers everyone who has saved a profile); (2) the OAuth provider round-trip (`get_oauth_user_from_propel_user_id` → `sub` → `fetch_user_by_user_id`), the best source for the OAuth-format `user_id` + avatar, lazily creating a doc for new users; (3) the PropelAuth user-metadata fallback (`_fetch_propel_metadata` → `auth.fetch_user_metadata_by_user_id`) — RELIABLE, does NOT depend on the provider token — which resolves an existing doc by email (backfilling `propel_id`) or lazily creates one from the metadata (`user_id` set to the propel UUID since we lack the oauth-format id without the provider call; `propel_id` is the canonical match so step 1 hits forever after).** The bug this fixes: the WRITE used to depend SOLELY on step 2; when `get_oauth_user_from_propel_user_id` returns None (expired/unavailable provider token, PropelAuth hiccup, or its 5-min negative cache) the write 404'd ("Couldn't log that time") while the read masked it by returning empty. **Critical:** `get_profile_metadata` (which creates the doc) ALSO depends on the OAuth round-trip, so a user whose OAuth has always failed may have NO doc at all — step 3 (metadata) is what resolves/creates them. `fetch_user_by_propel_id`/`fetch_user_by_email` live in `db/{db,firestore,mem}.py` (single-field equality queries — auto-indexed, no composite index). **Logging:** `get_oauth_user_from_propel_user_id` now logs the PropelAuth response BODY (truncated) on non-200 and a debug line when serving a cached miss — previously the root cause (e.g. "no linked OAuth connection", wrong `PROPEL_AUTH_URL`/`KEY`) was invisible during a tight retry window. Tests: `api/users/tests/test_volunteer_resolve.py` (6 cases). NOTE — date/locale is NOT a factor: `` always yields an ISO `yyyy-MM-dd` value regardless of the user's locale. `get_volunteering_time` now returns `([], 0, 0)` (never None/404) so the page shows a clean zero-state, and filters in a SINGLE pass — an entry may carry `commitmentHours`, `finalHours`, or BOTH (manual logs send both), no concat/duplicate. `save_volunteering_time` accepts an optional `timestamp` (backdated manual logs) + `manual:true` flag; hours are float-cleaned, non-negative, capped at 1000. ## Admin Email Templates (`email_templates` collection) Powers the frontend `/admin/communication` template editor and the volunteer send-email dialogs. Blueprint: `api/email_templates/email_templates_views.py` (`/api/admin/templates*`, all `volunteer.admin`-gated); service: `services/email_templates_service.py`; seed data: `services/email_templates_seed.py`. diff --git a/api/users/tests/__init__.py b/api/users/tests/__init__.py new file mode 100644 index 0000000..e69de29 diff --git a/api/users/tests/test_volunteer_resolve.py b/api/users/tests/test_volunteer_resolve.py new file mode 100644 index 0000000..054857a --- /dev/null +++ b/api/users/tests/test_volunteer_resolve.py @@ -0,0 +1,136 @@ +"""Tests for the volunteering identity-resolution fix. + +Regression coverage for the "Couldn't log that time" bug: the volunteering +WRITE used to depend solely on the live Slack/Google OAuth round-trip +(get_oauth_user_from_propel_user_id). When that returned None (expired/ +unavailable provider token, PropelAuth hiccup, or its negative cache), the +write 404'd even though the user clearly existed. + +_resolve_and_ensure_user now resolves in this order, so a broken provider token +can never block volunteering: + 1. by stored propel_id (no external call), + 2. OAuth provider round-trip (+ lazy-create), + 3. PropelAuth user-metadata fallback (reliable, no provider token) — resolve + an existing doc by email (backfill propel_id) or lazily create one. +""" +import os + +os.environ.setdefault("ENVIRONMENT", "test") # -> MockFirestore; no network at import + +import services.users_service as us +from model.user import User + + +def _boom(_propel_id): + raise AssertionError("OAuth round-trip must NOT be called when propel_id resolves") + + +def test_resolves_by_propel_id_without_oauth(monkeypatch): + user = User() + user.user_id = "oauth2|slack|T123-UABC" + user.propel_id = "propel-uuid-xyz" + monkeypatch.setattr(us, "fetch_user_by_propel_id", lambda pid: user if pid == "propel-uuid-xyz" else None) + monkeypatch.setattr(us, "get_oauth_user_from_propel_user_id", _boom) + + resolved, user_id = us._resolve_and_ensure_user("propel-uuid-xyz") + assert resolved is user + assert user_id == "oauth2|slack|T123-UABC" + + +def test_falls_back_to_oauth_when_no_propel_match(monkeypatch): + monkeypatch.setattr(us, "fetch_user_by_propel_id", lambda pid: None) + user = User() + user.user_id = "oauth2|slack|T123-UDEF" + monkeypatch.setattr( + us, "get_oauth_user_from_propel_user_id", + lambda pid: {"sub": "oauth2|slack|T123-UDEF", "email": "a@b.c", "name": "A", "given_name": "A"}, + ) + monkeypatch.setattr(us, "fetch_user_by_user_id", lambda uid: user) + + resolved, user_id = us._resolve_and_ensure_user("propel-no-doc") + assert resolved is user + assert user_id == "oauth2|slack|T123-UDEF" + + +def test_metadata_fallback_resolves_existing_by_email_and_backfills_propel_id(monkeypatch): + """OAuth down + no propel_id match -> resolve the existing doc by email and + backfill propel_id so future requests hit the fast path.""" + monkeypatch.setattr(us, "fetch_user_by_propel_id", lambda pid: None) + monkeypatch.setattr(us, "get_oauth_user_from_propel_user_id", lambda pid: None) # OAuth broken + monkeypatch.setattr(us, "_fetch_propel_metadata", lambda pid: { + "email": "greg@ohack.org", "name": "Greg", "nickname": "Greg", "profile_image": ""}) + + existing = User() + existing.user_id = "oauth2|slack|T123-UOLD" + existing.propel_id = None # never had propel_id set + monkeypatch.setattr(us, "fetch_user_by_email", lambda email: existing if email == "greg@ohack.org" else None) + + backfilled = {} + monkeypatch.setattr(us, "upsert_profile_metadata", lambda u: backfilled.update(propel_id=u.propel_id)) + + resolved, user_id = us._resolve_and_ensure_user("00216ceb-82ff-4528-ad11-dd45d02a0fa6") + assert resolved is existing + assert user_id == "oauth2|slack|T123-UOLD" + assert existing.propel_id == "00216ceb-82ff-4528-ad11-dd45d02a0fa6" + assert backfilled.get("propel_id") == "00216ceb-82ff-4528-ad11-dd45d02a0fa6" + + +def test_metadata_fallback_creates_doc_when_none_exists(monkeypatch): + """Brand-new user + OAuth down -> create a doc from PropelAuth metadata.""" + state = {"created": None} + monkeypatch.setattr(us, "fetch_user_by_propel_id", lambda pid: state["created"]) # None until created + monkeypatch.setattr(us, "get_oauth_user_from_propel_user_id", lambda pid: None) + monkeypatch.setattr(us, "fetch_user_by_email", lambda email: None) + monkeypatch.setattr(us, "_fetch_propel_metadata", lambda pid: { + "email": "new@ohack.org", "name": "New Person", "nickname": "New", "profile_image": "http://img"}) + + def fake_save_user(**kwargs): + u = User() + u.user_id = kwargs.get("user_id") + u.email_address = kwargs.get("email") + u.propel_id = kwargs.get("propel_id") + state["created"] = u + return u + monkeypatch.setattr(us, "save_user", fake_save_user) + + resolved, user_id = us._resolve_and_ensure_user("propel-brand-new") + assert resolved is state["created"] + assert resolved.propel_id == "propel-brand-new" + assert resolved.email_address == "new@ohack.org" + + +def test_manual_log_saves_combined_entry_without_oauth(monkeypatch): + user = User() + user.user_id = "oauth2|slack|T123-UGHI" + user.propel_id = "propel-manual" + user.volunteering = [] + monkeypatch.setattr(us, "fetch_user_by_propel_id", lambda pid: user) + monkeypatch.setattr(us, "get_oauth_user_from_propel_user_id", _boom) + monkeypatch.setattr(us, "upsert_profile_metadata", lambda u: None) + + res = us.save_volunteering_time("propel-manual", { + "commitmentHours": 4, + "finalHours": 4, + "reason": "coding", + "manual": True, + "timestamp": "2026-06-29T19:00:00.000Z", + }) + + assert res is user + entry = user.volunteering[-1] + assert entry["commitmentHours"] == 4 + assert entry["finalHours"] == 4 + assert entry["manual"] is True + assert entry["reason"] == "coding" + assert entry["timestamp"] == "2026-06-29T19:00:00.000Z" + + +def test_returns_none_when_identity_unresolvable(monkeypatch): + monkeypatch.setattr(us, "fetch_user_by_propel_id", lambda pid: None) + monkeypatch.setattr(us, "get_oauth_user_from_propel_user_id", lambda pid: None) + monkeypatch.setattr(us, "_fetch_propel_metadata", lambda pid: None) # metadata also unavailable + + user, user_id = us._resolve_and_ensure_user("ghost") + assert user is None and user_id is None + # And a write with no resolvable identity returns None (-> 404 at the view). + assert us.save_volunteering_time("ghost", {"finalHours": 1, "reason": "coding"}) is None diff --git a/db/db.py b/db/db.py index 667aec8..1d62a26 100644 --- a/db/db.py +++ b/db/db.py @@ -35,6 +35,12 @@ def fetch_user_by_db_id(id): u = db.fetch_user_by_db_id(id) return u +def fetch_user_by_propel_id(propel_id): + return db.fetch_user_by_propel_id(propel_id) + +def fetch_user_by_email(email): + return db.fetch_user_by_email(email) + def upsert_profile_metadata(user: User): return db.upsert_profile_metadata(user) diff --git a/db/firestore.py b/db/firestore.py index bf90cd3..754fa1b 100644 --- a/db/firestore.py +++ b/db/firestore.py @@ -113,6 +113,45 @@ def fetch_user_by_user_id_raw(self, db, user_id): pass return u + def fetch_user_by_propel_id(self, propel_id): + """Look up a user directly by the stored PropelAuth `propel_id` field. + + Single-field equality query (auto-indexed — no composite index needed). + Used to resolve identity WITHOUT the live OAuth provider round-trip, + which can fail (expired/unavailable token) and 404 a write even though + the user clearly exists. + """ + debug(logger, "Fetching user by propel_id", propel_id=propel_id) + if not propel_id: + return None + db = self.get_db() + raw = None + try: + raw, *rest = db.collection('users').where("propel_id", "==", propel_id).stream() + except ValueError: + # stream() yielded zero rows -> unpacking fails (same pattern as + # fetch_user_by_user_id_raw). Not found. + debug(logger, "No user found by propel_id", propel_id=propel_id) + return None + return convert_to_entity(raw, User) if raw is not None else None + + def fetch_user_by_email(self, email): + """Look up a user by `email_address`. Single-field equality query + (auto-indexed). Used as an identity fallback when neither propel_id nor + the OAuth round-trip resolves the user — email is stable across providers. + """ + debug(logger, "Fetching user by email") + if not email: + return None + db = self.get_db() + raw = None + try: + raw, *rest = db.collection('users').where("email_address", "==", email).stream() + except ValueError: + debug(logger, "No user found by email") + return None + return convert_to_entity(raw, User) if raw is not None else None + def fetch_user_by_db_id_raw(self, db, db_id): u = db.collection('users').document(db_id).get() return u diff --git a/db/mem.py b/db/mem.py index bc02377..ae1bd1d 100644 --- a/db/mem.py +++ b/db/mem.py @@ -92,6 +92,30 @@ def fetch_user_by_user_id(self, user_id): logger.debug(f'fetch_user_by_user_id error: {e}') return res + def fetch_user_by_propel_id(self, propel_id): + if not propel_id: + return None + res = None + try: + matches = list(self.users.where(lambda u: getattr(u, "propel_id", None) == propel_id)) + temp = matches[0] if matches else None + res = User.deserialize(vars(temp)) if temp is not None else None + except KeyError as e: + logger.debug(f'fetch_user_by_propel_id error: {e}') + return res + + def fetch_user_by_email(self, email): + if not email: + return None + res = None + try: + matches = list(self.users.where(lambda u: getattr(u, "email_address", None) == email)) + temp = matches[0] if matches else None + res = User.deserialize(vars(temp)) if temp is not None else None + except KeyError as e: + logger.debug(f'fetch_user_by_email error: {e}') + return res + def fetch_user_by_db_id_raw(self, id): res = None try: diff --git a/services/users_service.py b/services/users_service.py index 24f1b76..85c6de6 100644 --- a/services/users_service.py +++ b/services/users_service.py @@ -5,7 +5,7 @@ import requests from common.utils.slack import send_slack_audit from model.user import User -from db.db import delete_user_by_db_id, delete_user_by_user_id, fetch_user_by_user_id, fetch_user_by_db_id, fetch_users, insert_user, update_user, get_user_profile_by_db_id, upsert_profile_metadata +from db.db import delete_user_by_db_id, delete_user_by_user_id, fetch_user_by_user_id, fetch_user_by_db_id, fetch_user_by_propel_id, fetch_user_by_email, fetch_users, insert_user, update_user, get_user_profile_by_db_id, upsert_profile_metadata import pytz from cachetools import cached, LRUCache, TTLCache from cachetools.keys import hashkey @@ -187,6 +187,10 @@ def get_oauth_user_from_propel_user_id(propel_id): """ with _PROPEL_LOCK: if propel_id in _PROPEL_MISS_CACHE: + # Don't fail silently: a tight retry window otherwise shows only the + # caller's "could not resolve" warnings with no root cause, because + # the original failure reason was logged >5 min ago (or evicted). + debug(logger, "Serving cached OAuth miss (root cause logged earlier this TTL window)", propel_id=propel_id) return None if propel_id in _PROPEL_CACHE: return _PROPEL_CACHE[propel_id] @@ -201,8 +205,16 @@ def get_oauth_user_from_propel_user_id(propel_id): ) logger.debug(f"Propel RESP: {resp}") if resp.status_code != 200: - warning(logger, "PropelAuth API returned non-200", - status=resp.status_code, propel_id=propel_id) + # Log the response body (truncated) — the status alone doesn't tell us + # WHY (e.g. user has no linked OAuth connection, token revoked, wrong + # PROPEL_AUTH_URL/KEY env). This is the gap that hid the root cause. + body = "" + try: + body = resp.text[:300] + except Exception: + pass + warning(logger, "PropelAuth oauth_token API returned non-200", + status=resp.status_code, propel_id=propel_id, body=body) with _PROPEL_LOCK: _PROPEL_MISS_CACHE[propel_id] = _PROPEL_MISS return None @@ -399,40 +411,125 @@ def remove_user_by_slack_id(user_id): def get_users(): return fetch_users() +def _fetch_propel_metadata(propel_id): + """Fetch PropelAuth user metadata (email/name/avatar) for a propel_id. + + This hits PropelAuth's user-metadata API, which is RELIABLE and does NOT + depend on the OAuth provider (Slack/Google) token — unlike + get_oauth_user_from_propel_user_id, which calls the provider's userinfo + endpoint and fails when the provider token is missing/expired. Returns a + plain dict {email, name, nickname, profile_image} or None. + """ + try: + from common.auth import auth # lazy import: keeps this module cheap to import/test + meta = auth.fetch_user_metadata_by_user_id(propel_id) + except Exception as e: # network / SDK / not-found + warning(logger, "PropelAuth fetch_user_metadata_by_user_id failed", propel_id=propel_id, error=str(e)) + return None + if meta is None: + warning(logger, "PropelAuth returned no metadata for user", propel_id=propel_id) + return None + email = getattr(meta, "email", None) or "" + first = getattr(meta, "first_name", None) or "" + last = getattr(meta, "last_name", None) or "" + name = (f"{first} {last}".strip()) or getattr(meta, "username", None) or email + return { + "email": email, + "name": name, + "nickname": first, + "profile_image": getattr(meta, "picture_url", None) or "", + } + + def _resolve_and_ensure_user(propel_id): - """Resolve a propel_id to a Firestore User, lazily creating the user doc - when the person has authenticated but never opened their profile page (the - documented lazy-creation gotcha). Returns (user, user_id); (None, None) only - when PropelAuth identity can't be resolved at all (transient OAuth failure). - - Before this, the volunteering endpoints returned None -> 404 for any user - without a pre-existing doc, which surfaced as "Failed to load your volunteer - data" and also blocked them from starting a session. New users now just work. + """Resolve a propel_id to a Firestore User, lazily creating the doc for + brand-new users. Returns (user, user_id); (None, None) only when NO identity + source can resolve the user. + + Resolution order — most-reliable first, so a broken OAuth provider token can + never block volunteering: + 1. **Direct lookup by the stored `propel_id` field** — no external call. + Covers everyone who has saved a profile (propel_id is set then). + 2. **OAuth provider round-trip** (`get_oauth_user_from_propel_user_id` -> + provider `sub` -> user_id lookup) — yields the OAuth-format user_id + + provider avatar; lazily creates a doc for a brand-new user. + 3. **PropelAuth user-metadata fallback** (`fetch_user_metadata_by_user_id`) + — reliable, does NOT depend on the provider token. Resolves an existing + doc by email (backfilling propel_id), else lazily creates one from the + metadata. This is what saves the user when #1 misses AND the OAuth + round-trip is down. + + The bug history: the WRITE used to depend SOLELY on #2. When the provider + round-trip returned None (expired/unavailable token, PropelAuth hiccup, or + its 5-min negative cache), the write 404'd ("Couldn't log that time") while + the read masked it by returning empty data. #1 + #3 remove that dependency. + Once a doc is created/backfilled with propel_id, every later request hits #1. """ + # 1) Fast, reliable path: existing doc carries propel_id. + user = fetch_user_by_propel_id(propel_id) + if user is not None: + return user, (user.user_id or propel_id) + + # 2) OAuth provider round-trip — best source (OAuth-format user_id + avatar). oauth_user = get_oauth_user_from_propel_user_id(propel_id) - if oauth_user is None: - warning(logger, "Could not get OAuth user from PropelAuth", propel_id=propel_id) + if oauth_user is not None: + user_id = oauth_user["sub"] + user = fetch_user_by_user_id(user_id) + if user is None: + info(logger, "Lazily creating user doc on first volunteering action", user_id=user_id) + save_user( + user_id=user_id, + email=oauth_user.get("email", ""), + last_login=datetime.now().isoformat() + "Z", + profile_image=( + oauth_user.get("https://slack.com/user_image_192") + or oauth_user.get("picture") + or "" + ), + name=oauth_user.get("name", ""), + nickname=oauth_user.get("given_name", ""), + propel_id=propel_id, + ) + user = fetch_user_by_user_id(user_id) + return user, user_id + + # 3) OAuth is down — fall back to PropelAuth metadata (no provider token). + info(logger, "OAuth round-trip unavailable; resolving via PropelAuth metadata", propel_id=propel_id) + meta = _fetch_propel_metadata(propel_id) + if meta is None or not meta.get("email"): + warning(logger, "Could not resolve user by propel_id, OAuth, or metadata", propel_id=propel_id) return None, None - user_id = oauth_user["sub"] - user = fetch_user_by_user_id(user_id) + email = meta["email"] + user = fetch_user_by_email(email) + if user is not None: + # Backfill propel_id so every future request hits the fast path (#1). + if getattr(user, "propel_id", None) != propel_id: + user.propel_id = propel_id + try: + upsert_profile_metadata(user) + except Exception as e: + warning(logger, "Failed to backfill propel_id on user", propel_id=propel_id, error=str(e)) + return user, (user.user_id or propel_id) + + # Brand-new user, OAuth down: create a doc from metadata. user_id is set to + # the propel UUID (we lack the oauth-format id without the provider call); + # propel_id is the canonical match, so #1 resolves this user from now on. + info(logger, "Lazily creating user doc from PropelAuth metadata (OAuth unavailable)", propel_id=propel_id) + save_user( + user_id=propel_id, + email=email, + last_login=datetime.now().isoformat() + "Z", + profile_image=meta.get("profile_image", ""), + name=meta.get("name", ""), + nickname=meta.get("nickname", ""), + propel_id=propel_id, + ) + user = fetch_user_by_propel_id(propel_id) or fetch_user_by_email(email) if user is None: - info(logger, "Lazily creating user doc on first volunteering action", user_id=user_id) - save_user( - user_id=user_id, - email=oauth_user.get("email", ""), - last_login=datetime.now().isoformat() + "Z", - profile_image=( - oauth_user.get("https://slack.com/user_image_192") - or oauth_user.get("picture") - or "" - ), - name=oauth_user.get("name", ""), - nickname=oauth_user.get("given_name", ""), - propel_id=propel_id, - ) - user = fetch_user_by_user_id(user_id) - return user, user_id + warning(logger, "Metadata-based user creation did not yield a doc", propel_id=propel_id) + return None, None + return user, (user.user_id or propel_id) def save_volunteering_time(propel_id, json):