Make a refused presence claim diagnosable from our logs, not from the reply

src/api/analysis_summary.py

@@ -38,7 +38,12 @@
     VERDICT_INSTRUCTION,
     prompt_input,
 )
-from util.caller_token import TokenRejectedError, human_presence_reason, verify
+from util.caller_token import (
+    TokenRejectedError,
+    human_presence_detail,
+    human_presence_reason,
+    verify,
+)
 from util.logging import logging
 from util.rate_limit import identity_of, limiter_from_env
 
@@ -123,7 +128,14 @@ async def analysis_summary(body: SummaryRequest, request: Request) -> StreamingR
     # Stricter than the answer endpoint, and checked before any model call.
     presence = human_presence_reason(claims, time.time())
     if presence:
-        return _refusal(presence, presence)
+        # The caller gets the coarse reason; the log gets the specific one,
+        # so an integrator's "we get no_human" is answerable by looking.
+        detail = (
+            human_presence_detail(claims, time.time())
+            if presence == "no_human"
+            else presence
+        )
+        return _refusal(presence, detail)
 
     if body.disclosure not in IMPLEMENTED_TIERS:
         return _refusal("unsupported_tier", f"tier {body.disclosure} is not built")

src/util/caller_token.py

@@ -172,6 +172,55 @@ def verify(token: str, verifying_key: str, *, audience: str | None = None) -> di
 HUMAN_MAX_AGE_SECONDS = 1800
 
 
+def human_presence_detail(claims: dict, now: float) -> str:
+    """Why the presence claim failed, **for our logs only**.
+
+    The reason returned to the caller is deliberately coarse: `no_human`
+    whether the claim was absent, malformed or from the future, so this side
+    cannot be used to probe what a valid claim looks like.
+
+    That coarseness has a cost, and it was paid on 2026-09-21. The website
+    hand-built a test claim using their cookie's internal field names
+    (`subject`, `solvedAt`) rather than the agreed JWT claims, got `no_human`
+    twice, and was one step from concluding this gate was rejecting their
+    valid tokens.
+
+    Takes the same `now` as `human_presence_reason`, because the two must
+    agree about the present as well as about the causes. Two identical wrong answers read as a finding rather than
+    as one mistake made twice.
+
+    So the distinction lives here, in the log, where an integrator's "we get
+    no_human" can be answered by looking rather than by guessing. Never put
+    this in the response.
+    """
+    if "human" not in claims:
+        return "no `human` claim present"
+    if claims.get("human") is not True:
+        # Truncated: this is a signed claim so the value is the website's,
+        # but an unbounded repr in a log line is a bad habit to keep.
+        return f"`human` present but not true ({claims.get('human')!r:.80})"
+    if "human_iat" not in claims:
+        return "`human` true but no `human_iat`"
+    issued = claims.get("human_iat")
+    if not isinstance(issued, int | float) or isinstance(issued, bool):
+        return f"`human_iat` is not a number ({type(issued).__name__})"
+    # The same clock the reason used. Taking `time()` here instead was an
+    # inconsistency that only showed when a caller supplied a different
+    # `now` -- the two functions disagreeing about the present, in the
+    # function written to stop them disagreeing.
+    if int(issued) > int(now) + 60:
+        return "`human_iat` is in the future; clocks disagree"
+    # Reached only if `human_presence_reason` has grown a `no_human` branch
+    # this function does not know about. Saying so is the honest answer; the
+    # previous version returned the clock message as a catch-all, which would
+    # have sent an integrator confidently after the wrong cause -- the exact
+    # failure this whole function exists to prevent, one level in.
+    return (
+        "no known cause matched; human_presence_detail is out of step with "
+        "human_presence_reason"
+    )
+
+
 def human_presence_reason(claims: dict, now: float) -> str | None:
     """None when a person is vouched for; otherwise why not.
 

tests/api/test_analysis_summary.py

@@ -121,7 +121,9 @@ def _client(public_pem: str) -> TestClient:
     return TestClient(app)
 
 
-def _token(private_pem: str, **claims: object) -> str:
+def _token(private_pem: str, omit: tuple[str, ...] = (), **claims: object) -> str:
+    """`omit` removes a claim entirely, which is different from setting it to
+    None -- and the difference is the whole point of the absence cases."""
     payload: dict[str, object] = {
         "iss": "reactome-website",
         "aud": DEFAULT_AUDIENCE,
@@ -131,6 +133,8 @@ def _token(private_pem: str, **claims: object) -> str:
         "human_iat": int(time.time()) - 10,
     }
     payload.update(claims)
+    for key in omit:
+        payload.pop(key, None)
     return jwt.encode(payload, private_pem, algorithm="EdDSA")
 
 
@@ -747,3 +751,42 @@ async def astream(self, messages: Any) -> AsyncIterator[Any]:
     # this assertion first passed review while testing nothing.
     assert "expression_columns" in prompt
     assert re.search(r'expression_columns\\?":\s*3', prompt), prompt[-200:]
+
+
+@pytest.mark.parametrize(
+    ("omit", "claims", "expected_log"),
+    [
+        # Absent, which is what the website's hand-built claim effectively
+        # was: they sent `subject` and `solvedAt`, so neither agreed claim
+        # was there at all.
+        (("human",), {}, "no `human` claim present"),
+        ((), {"human": "yes"}, "present but not true"),
+        (("human_iat",), {"human": True}, "no `human_iat`"),
+        ((), {"human": True, "human_iat": "solvedAt"}, "not a number"),
+    ],
+)
+def test_the_specific_presence_failure_is_logged_but_never_returned(
+    keys: tuple[str, str],
+    caplog: pytest.LogCaptureFixture,
+    omit: tuple[str, ...],
+    claims: dict[str, Any],
+    expected_log: str,
+) -> None:
+    # The caller gets a coarse `no_human` whatever went wrong, so this side
+    # cannot be probed for what a valid claim looks like. The cost of that
+    # was paid on 2026-09-21: the website hand-built a claim with their
+    # cookie's field names, got `no_human` twice, and nearly concluded our
+    # gate was rejecting their valid tokens.
+    #
+    # So the distinction lives in the log. Both halves are asserted, because
+    # either alone is the bug: a coarse log is undiagnosable and a detailed
+    # response is a probe.
+    private, public = keys
+    with caplog.at_level("INFO", logger="api.analysis_summary"):
+        response = _post(public, caller_token=_token(private, omit=omit, **claims))
+
+    payload = _events(response.text)[-1][1]
+    assert payload["reason"] == "no_human"
+    logged = " ".join(r.getMessage() for r in caplog.records)
+    assert expected_log in logged, f"not diagnosable from the log: {logged}"
+    assert expected_log not in response.text, "the detail reached the caller"

tests/util/test_caller_token.py

@@ -26,6 +26,8 @@
     KEY_PATH_ENV,
     TokenRejectedError,
     expected_audience,
+    human_presence_detail,
+    human_presence_reason,
     load_verifying_key,
     verify,
 )
@@ -202,3 +204,57 @@ def test_the_key_is_read_from_the_configured_path(
     path = tmp_path / "public.pem"
     path.write_text(public_pem)
     assert load_verifying_key(str(path)).startswith("-----BEGIN PUBLIC KEY-----")
+
+
+def test_every_no_human_cause_has_a_matching_detail() -> None:
+    """The two functions must agree on what produces `no_human`.
+
+    They are separate, with nothing linking them. The detail function used to
+    end with the clock message as a catch-all, so a new `no_human` branch in
+    `human_presence_reason` would have been reported confidently as a clock
+    disagreement -- sending an integrator after the wrong cause, which is the
+    failure the detail exists to prevent.
+
+    Enumerated rather than asserted in prose, so adding a cause without a
+    detail fails here.
+    """
+    now = 1_700_000_000
+    causes: list[dict[str, object]] = [
+        {},
+        {"human": False},
+        {"human": "yes"},
+        {"human": True},
+        {"human": True, "human_iat": None},
+        {"human": True, "human_iat": "solvedAt"},
+        {"human": True, "human_iat": True},
+        {"human": True, "human_iat": now + 3600},
+    ]
+    for claims in causes:
+        assert human_presence_reason(claims, now) == "no_human", claims
+        detail = human_presence_detail(claims, now)
+        assert "out of step" not in detail, f"no detail for {claims}: {detail}"
+
+
+def test_a_long_human_value_is_not_logged_whole() -> None:
+    # A signed claim, so the value is the website's -- but an unbounded repr
+    # in a log line is a habit worth not having.
+    detail = human_presence_detail({"human": "x" * 5000}, 1_700_000_000)
+    assert len(detail) < 200
+
+
+def test_the_detail_admits_when_it_has_no_cause_rather_than_inventing_one() -> None:
+    """Called on claims that are not a failure, it must say so.
+
+    This is the guard the enumeration above cannot provide. That test checks
+    every *known* cause has a detail, which passes just as well if the
+    function ends with a plausible catch-all -- and a catch-all is exactly
+    the bug: a new `no_human` branch would then be reported confidently as
+    whatever the last line happens to say.
+
+    A valid claim reaches the end of the function, so it is the one input
+    that distinguishes an honest fallback from a confident one.
+    """
+    now = 1_700_000_000
+    valid = {"human": True, "human_iat": now - 10}
+    assert human_presence_reason(valid, now) is None
+    assert "out of step" in human_presence_detail(valid, now)