diff --git a/apps/auth/tests/__init__.py b/apps/auth/tests/__init__.py new file mode 100644 index 0000000..e69de29 diff --git a/apps/auth/tests/test_clock_offset.py b/apps/auth/tests/test_clock_offset.py new file mode 100644 index 0000000..84d1b8d --- /dev/null +++ b/apps/auth/tests/test_clock_offset.py @@ -0,0 +1,254 @@ +"""Tests for the dynamic WJ clock-offset sync mechanism in apps.auth. + +Background: the WJ questionnaire platform's server clock runs slow and +drifts (~7s/day), which broke the fixed 220s submission-timestamp window. +These tests cover offset estimation from the HTTP Date header, the Redis +EWMA rolling estimate, and the offset-corrected validity check in +verify_callback_api. +""" + +import hashlib +import json +import time +from datetime import datetime, timedelta, timezone +from email.utils import formatdate +from http.cookies import SimpleCookie + +import httpx +import pytest +from rest_framework.test import APIClient + +from apps.auth import utils, views + +# --------------------------------------------------------------------------- +# In-memory fake Redis (test env has no guaranteed cache container) +# --------------------------------------------------------------------------- + + +class FakeRedis: + def __init__(self): + self.store = {} + + def _bytes(self, value): + if isinstance(value, str): + return value.encode("utf-8") + return value + + def get(self, key): + v = self.store.get(key) + return self._bytes(v) if not isinstance(v, dict) else v + + def setex(self, key, ttl, value): + self.store[key] = value + + def getdel(self, key): + v = self.store.pop(key, None) + return self._bytes(v) if not isinstance(v, dict) else v + + def incr(self, key): + n = int(self.store.get(key, 0)) + 1 + self.store[key] = str(n) + return n + + def expire(self, key, ttl): + return 1 if key in self.store else 0 + + def delete(self, *keys): + for k in keys: + self.store.pop(k, None) + + def hset(self, key, mapping=None): + h = self.store.setdefault(key, {}) + h.update({mk: str(mv) for mk, mv in (mapping or {}).items()}) + + def hget(self, key, field): + h = self.store.get(key) + if isinstance(h, dict) and field in h: + return h[field].encode("utf-8") + return None + + +@pytest.fixture +def fake_redis(monkeypatch): + r = FakeRedis() + monkeypatch.setattr(views, "get_redis_connection", lambda conn: r) + monkeypatch.setattr(utils, "get_redis_connection", lambda conn: r) + return r + + +# --------------------------------------------------------------------------- +# estimate_wj_clock_offset +# --------------------------------------------------------------------------- + + +def _response_with_date(server_offset_s, elapsed_s=0.2): + """Fake httpx response whose Date header is server_offset_s off true time.""" + date_str = formatdate(time.time() + server_offset_s, usegmt=True) + resp = httpx.Response(200, headers={"date": date_str}) + resp._elapsed = timedelta(seconds=elapsed_s) + return resp + + +class TestEstimateWjClockOffset: + def test_detects_slow_server(self): + offset = utils.estimate_wj_clock_offset(_response_with_date(-230)) + assert offset is not None + assert -232.5 < offset < -227.5 + + def test_zero_offset(self): + offset = utils.estimate_wj_clock_offset(_response_with_date(0)) + assert offset is not None + assert abs(offset) < 2.5 + + def test_missing_date_header_returns_none(self): + resp = httpx.Response(200) + assert utils.estimate_wj_clock_offset(resp) is None + + def test_invalid_date_header_returns_none(self): + resp = httpx.Response(200, headers={"date": "garbage-not-a-date"}) + assert utils.estimate_wj_clock_offset(resp) is None + + +# --------------------------------------------------------------------------- +# record / get cached EWMA +# --------------------------------------------------------------------------- + + +class TestRollingEstimate: + def test_first_sample_stored_verbatim(self, fake_redis): + utils.record_wj_clock_offset(-230.0) + assert utils.get_cached_wj_clock_offset() == pytest.approx(-230.0) + + def test_ewma_blend_of_two_samples(self, fake_redis): + utils.record_wj_clock_offset(-230.0) + utils.record_wj_clock_offset(-240.0) + # alpha=0.3: 0.3*-240 + 0.7*-230 = -233 + assert utils.get_cached_wj_clock_offset() == pytest.approx(-233.0) + + def test_no_estimate_returns_none(self, fake_redis): + assert utils.get_cached_wj_clock_offset() is None + + +# --------------------------------------------------------------------------- +# verify_callback_api validity-window integration +# --------------------------------------------------------------------------- + +ACCOUNT = "testaccount" +OTP = "12345678" +ANSWER_ID = 999 +VERIFY_URL = "/api/auth/verify/" + + +def _seed_flow(fake_redis, temp_token, initiated_at, action="signup"): + token_hash = hashlib.sha256(temp_token.encode()).hexdigest() + fake_redis.store[f"temp_token_state:{token_hash}"] = json.dumps( + {"status": "pending", "action": action} + ) + fake_redis.store[f"otp:{OTP}"] = json.dumps( + {"temp_token": temp_token, "initiated_at": initiated_at} + ) + + +def _answer(offset, submitted_local, server_clock_offset="same"): + """Build get_latest_answer payload: submission at submitted_local (our frame) + reported in the WJ frame (= local + offset). server_clock_offset="same" + means the fresh Date-header sample equals the true drift; pass None to + simulate a missing sample.""" + submitted_wj = datetime.fromtimestamp(submitted_local + offset, tz=timezone.utc) + value = offset if server_clock_offset == "same" else server_clock_offset + data = { + "id": ANSWER_ID, + "submitted_at": submitted_wj.isoformat(), + "account": ACCOUNT, + "otp": OTP, + "server_clock_offset": value, + } + return data + + +@pytest.fixture +def verify_client(monkeypatch, fake_redis): + """Client + a knob to inject the mocked get_latest_answer payload.""" + + state = {"answer": None} + + async def fake_get_latest_answer(action, account): + return state["answer"], None + + monkeypatch.setattr(utils, "get_latest_answer", fake_get_latest_answer) + + def make_client(temp_token): + client = APIClient() + client.cookies = SimpleCookie() + client.cookies["temp_token"] = temp_token + return client + + def call(answer, temp_token="tok-" + "x" * 20): + state["answer"] = answer + return make_client(temp_token).post( + VERIFY_URL, + {"account": ACCOUNT, "answer_id": ANSWER_ID, "action": "signup"}, + format="json", + ) + + call.redis = fake_redis + return call + + +class TestVerifyWindowWithOffset: + def test_large_drift_accepted_after_correction(self, verify_client): + # WJ 300s slow, user filled survey 60s after initiate. + # Raw diff = -240s would fail the legacy 220s window; corrected + # diff = +60s must pass. + now = time.time() + _seed_flow(verify_client.redis, "tok-" + "x" * 20, initiated_at=now) + resp = verify_client(_answer(offset=-300, submitted_local=now + 60)) + assert resp.status_code == 200, resp.data + + def test_stale_replay_still_rejected(self, verify_client): + # Genuine-looking offset, but submission an hour BEFORE initiation. + now = time.time() + _seed_flow(verify_client.redis, "tok-" + "x" * 20, initiated_at=now) + resp = verify_client(_answer(offset=-300, submitted_local=now - 3600)) + assert resp.status_code == 401 + assert "validity window" in str(resp.data.get("error", "")) + + def test_no_offset_available_uses_legacy_tolerance(self, verify_client): + # No fresh sample, no cache -> legacy 220s window on raw diff -180s. + now = time.time() + _seed_flow(verify_client.redis, "tok-" + "x" * 20, initiated_at=now) + resp = verify_client( + _answer(offset=-180, submitted_local=now + 40, server_clock_offset=None) + ) + assert resp.status_code == 200, resp.data + + def test_legacy_tolerance_still_rejects_beyond_220(self, verify_client): + # No offset data at all, raw diff -240s -> legacy rejects (old behavior). + now = time.time() + _seed_flow(verify_client.redis, "tok-" + "x" * 20, initiated_at=now) + resp = verify_client( + _answer(offset=-300, submitted_local=now + 60, server_clock_offset=None) + ) + assert resp.status_code == 401 + + def test_cached_offset_corrects_when_fresh_sample_missing(self, verify_client): + # server_clock_offset missing from payload; EWMA cache says -300. + # Raw diff -240 fails legacy 220, but cached correction accepts. + utils.record_wj_clock_offset(-300.0) + now = time.time() + _seed_flow(verify_client.redis, "tok-" + "x" * 20, initiated_at=now) + answer = _answer(offset=-300, submitted_local=now + 60) + answer["server_clock_offset"] = None + resp = verify_client(answer) + assert resp.status_code == 200, resp.data + + def test_future_submission_beyond_window_rejected(self, verify_client): + # WJ 250s fast: corrected submission sits far past OTP window upper + # bound -> reject (also sanity-checks the +tolerance upper-bound math). + utils.record_wj_clock_offset(250.0) + now = time.time() + _seed_flow(verify_client.redis, "tok-" + "x" * 20, initiated_at=now) + resp = verify_client( + _answer(offset=250, submitted_local=now + 750), + ) + assert resp.status_code == 401 diff --git a/apps/auth/utils.py b/apps/auth/utils.py index 3e63695..56081c8 100644 --- a/apps/auth/utils.py +++ b/apps/auth/utils.py @@ -1,6 +1,8 @@ import json import logging import re +import time +from email.utils import parsedate_to_datetime from typing import Any import httpx @@ -9,6 +11,7 @@ from django.contrib.auth.models import AbstractUser from django.contrib.auth.password_validation import validate_password from django.core.exceptions import ValidationError +from django_redis import get_redis_connection from rest_framework.authentication import SessionAuthentication from rest_framework.response import Response @@ -19,7 +22,7 @@ AUTH_SETTINGS = settings.AUTH PASSWORD_LENGTH_MIN = AUTH_SETTINGS["PASSWORD_LENGTH_MIN"] PASSWORD_LENGTH_MAX = AUTH_SETTINGS["PASSWORD_LENGTH_MAX"] -OTP_TIMEOUT = AUTH_SETTINGS["OTP_TIMEOUT"] +OTP_TIMEOUT = int(AUTH_SETTINGS["OTP_TIMEOUT"]) EMAIL_DOMAIN_NAME = AUTH_SETTINGS["EMAIL_DOMAIN_NAME"] QUEST_SETTINGS = settings.QUEST @@ -46,7 +49,7 @@ def get_survey_details(action: str) -> dict[str, Any] | None: try: question_id = int(action_details.get("QUESTIONID")) - except ValueError, TypeError: + except (ValueError, TypeError): # fmt: skip logger.error( "Could not parse 'QUESTIONID' for action '%s'. Check your settings.", action ) @@ -90,6 +93,67 @@ async def verify_turnstile_token( return False, Response({"error": "Turnstile verification error"}, status=500) +WJ_CLOCK_OFFSET_KEY = "wj:clock:offset" +WJ_CLOCK_OFFSET_TTL = 48 * 3600 +WJ_CLOCK_EWMA_ALPHA = 0.3 + + +def estimate_wj_clock_offset(response: httpx.Response) -> float | None: + """Estimate WJ server clock offset (wj_time - local_time) in seconds. + + Negative means the WJ clock runs slow (currently ~-230s and drifting + ~7s/day). Derived from the response `Date` header with request-RTT + midpoint correction. The `Date` header and the `submitted_at` field + come from the same WJ server clock domain (verified 2026-09-08: header + offset matches the measured submitted_at drift history), so this offset + corrects `submitted_at` before validity-window checks. + """ + date_str = response.headers.get("date") + if not date_str: + return None + try: + wj_time = parsedate_to_datetime(date_str) + except (TypeError, ValueError): # fmt: skip + return None + if wj_time is None: # fmt: skip + return None + try: + elapsed = response.elapsed.total_seconds() + except (RuntimeError, AttributeError): # fmt: skip + elapsed = 0.0 + receive_time = time.time() + send_time = receive_time - elapsed + local_midpoint = (send_time + receive_time) / 2.0 + return wj_time.timestamp() - local_midpoint + + +def record_wj_clock_offset(offset: float) -> None: + """Fold a fresh offset sample into the rolling EWMA estimate in Redis.""" + try: + r = get_redis_connection("default") + existing = r.hget(WJ_CLOCK_OFFSET_KEY, "offset") + if existing is not None: + offset = WJ_CLOCK_EWMA_ALPHA * offset + (1 - WJ_CLOCK_EWMA_ALPHA) * float( + existing + ) + r.hset( + WJ_CLOCK_OFFSET_KEY, mapping={"offset": offset, "updated_at": time.time()} + ) + r.expire(WJ_CLOCK_OFFSET_KEY, WJ_CLOCK_OFFSET_TTL) + except Exception: + logger.warning("Failed to record WJ clock offset", exc_info=True) + + +def get_cached_wj_clock_offset() -> float | None: + """Rolling EWMA offset estimate from Redis, or None if unavailable/stale.""" + try: + r = get_redis_connection("default") + cached = r.hget(WJ_CLOCK_OFFSET_KEY, "offset") + return float(cached) if cached is not None else None + except Exception: + return None + + async def get_latest_answer( action: str, account: str, @@ -140,6 +204,9 @@ async def get_latest_answer( ) response.raise_for_status() # Raise an exception for bad status codes full_data = response.json() + offset_sample = estimate_wj_clock_offset(response) + if offset_sample is not None: + record_wj_clock_offset(offset_sample) except httpx.TimeoutException: logger.error("Questionnaire API query timed out") return None, Response( @@ -182,6 +249,9 @@ async def get_latest_answer( if latest_answer.get("user") else None, "otp": otp, + # WJ clock offset measured from this response's Date header + # (may be None if header missing/unparseable) + "server_clock_offset": offset_sample, } # Check if all required fields are present diff --git a/apps/auth/views.py b/apps/auth/views.py index 01aafb0..34e6822 100644 --- a/apps/auth/views.py +++ b/apps/auth/views.py @@ -25,7 +25,7 @@ AUTH_SETTINGS = settings.AUTH -OTP_TIMEOUT = AUTH_SETTINGS["OTP_TIMEOUT"] +OTP_TIMEOUT = int(AUTH_SETTINGS["OTP_TIMEOUT"]) TEMP_TOKEN_TIMEOUT = AUTH_SETTINGS["TEMP_TOKEN_TIMEOUT"] ACTION_LIST = AUTH_SETTINGS["ACTION_LIST"] TOKEN_RATE_LIMIT = AUTH_SETTINGS["TOKEN_RATE_LIMIT"] @@ -261,15 +261,68 @@ def verify_callback_api(request): submitted_at = dateutil.parser.parse(submitted_at_str).timestamp() - # Additional validation: check submission is after initiation and within window - if submitted_at < initiated_at or (submitted_at - initiated_at) > OTP_TIMEOUT: + # Validation: submission must be after initiation and within the OTP + # window. The WJ platform's server clock runs slow and drifts over + # time (~7s/day; measured ~-230s on 2026-09-08), so we dynamically + # correct submitted_at by the WJ clock offset before checking. The + # offset is sampled from the WJ API response's Date header on every + # get_latest_answer call (NTP-style, same clock domain as + # submitted_at); we prefer this request's fresh sample, falling back + # to the rolling EWMA in Redis, then to legacy fixed tolerance. + clock_offset = latest_answer.get("server_clock_offset") + if clock_offset is None: + clock_offset = utils.get_cached_wj_clock_offset() + + if clock_offset is not None: + corrected_submitted_at = submitted_at - clock_offset + timestamp_tolerance = AUTH_SETTINGS.get("TIMESTAMP_JITTER_TOLERANCE", 60) + else: + # No offset data available (cold start with WJ not sending a + # usable Date header) — legacy behavior. + corrected_submitted_at = submitted_at + timestamp_tolerance = 220 + logger.warning( + "No WJ clock offset available; falling back to legacy " + "tolerance=220s (submitted_at=%s initiated_at=%s)", + submitted_at, + initiated_at, + ) + + if ( + corrected_submitted_at + timestamp_tolerance < initiated_at + or (corrected_submitted_at - initiated_at) > OTP_TIMEOUT + timestamp_tolerance + ): # fmt: skip + logger.warning( + "Submission timestamp outside validity window: " + "submitted_at=%s initiated_at=%s raw_diff=%.1fs " + "clock_offset=%.1fs corrected_diff=%.1fs tolerance=%ss", + submitted_at, + initiated_at, + submitted_at - initiated_at, + clock_offset if clock_offset is not None else 0.0, + corrected_submitted_at - initiated_at, + timestamp_tolerance, + ) return Response( {"error": "Submission timestamp outside validity window"}, status=401, ) - except ValueError, TypeError: - logger.error("Error parsing submission timestamp") + logger.info( + "Clock offset applied: offset=%.1fs raw_diff=%.1fs corrected_diff=%.1fs", + clock_offset if clock_offset is not None else 0.0, + submitted_at - initiated_at, + corrected_submitted_at - initiated_at, + ) + + except (ValueError, TypeError) as e: + logger.error( + "Error parsing submission timestamp: submitted_at_str=%r " + "initiated_at=%r exception=%s", + locals().get("submitted_at_str"), + locals().get("initiated_at"), + e, + ) return Response({"error": "Invalid submission timestamp"}, status=401) # Step 7: Update state to verified and add user details diff --git a/website/settings.py b/website/settings.py index d281cf3..50796e9 100644 --- a/website/settings.py +++ b/website/settings.py @@ -31,6 +31,11 @@ "PASSWORD_LENGTH_MAX": 32, "EMAIL_DOMAIN_NAME": "sjtu.edu.cn", "ACTION_LIST": ["signup", "login", "reset_password"], + # Residual jitter tolerance (seconds) applied to the WJ submission + # timestamp AFTER dynamic clock-offset correction (see + # apps/auth/utils.estimate_wj_clock_offset). Covers Date-header + # 1s resolution, RTT asymmetry, and platform processing delay. + "TIMESTAMP_JITTER_TOLERANCE": 60, }, "DATABASE": {"URL": "sqlite:///db.sqlite3"}, "REDIS": {"URL": "redis://localhost:6379/0", "MAX_CONNECTIONS": 100},