diff --git a/app/build.gradle.kts b/app/build.gradle.kts index e24b5d7c..a856617b 100644 --- a/app/build.gradle.kts +++ b/app/build.gradle.kts @@ -447,7 +447,7 @@ chaquopy { // wheel for desktop platforms and a pure-Python `py3-none-any` one as well. // There is no Android wheel, so pip falls back to the pure-Python build - which // is correct but markedly slower. The messages here are small enough not to care. - install("git+https://github.com/parawanderer/FindMy.py@d956fc8b2679be56b0f4b0053940c5091fc0f1bb") + install("git+https://github.com/parawanderer/FindMy.py@7969003ca785658369b650f75d9e7ca519566bf6") install("NSKeyedUnArchiver==1.5") diff --git a/app/src/main/python/icloud_bridge.py b/app/src/main/python/icloud_bridge.py index c2085031..2b85beb8 100644 --- a/app/src/main/python/icloud_bridge.py +++ b/app/src/main/python/icloud_bridge.py @@ -38,6 +38,7 @@ import json import plistlib import sys +import time import traceback from typing import Any @@ -130,6 +131,30 @@ naming record as its single source of truth. """ +APPLE_RETRY_BACKOFF_SECONDS = (1.0, 3.0) +""" +How long to wait before each retry of a refusal that clears on its own. + +**Two retries, because one refusal in the middle of a flow is what users actually meet.** Apple's +edge refuses the occasional request on a fresh connection and answers the next one normally - see +OpenTagViewer#226, where a probe measured it directly and the app met it twice in one sitting on +the account-setup screen. Both times pressing "Try Again" worked, which is the whole argument: +the app is asking somebody to do by hand, twice, what it can do in a second. + +Four seconds of extra patience in total. That cannot hide a real outage - the September 2026 +edge block lasted days and would still arrive at the screen - and it is short enough that the +loading indicator already on screen covers it. +""" + +APPLE_RETRY_CEILING_SECONDS = 5.0 +""" +The longest wait this will sit through when Apple names one in `Retry-After`. + +Apple's own number beats any guess, but a header asking for a minute is information for the +person rather than something to block a screen on. Past this, the refusal is surfaced with the +wait attached, which is what `REASON_APPLE_DECLINED` already knows how to show. +""" + REASON_APPLE_DECLINED = "apple_declined" """ Apple answered and refused to serve. Worth waiting out, and not the user's fault. @@ -337,6 +362,56 @@ def __init__(self, account: Any, asyncAccount: Any, loop: Any) -> None: self._sponsor: Any = None self._candidates: dict[str, Any] = {} + def _awaiting(self, makeCall, what: str): + """ + Run an async call, retrying the refusals that clear on their own. + + **A factory, not a coroutine.** A coroutine can only be awaited once, so a retry needs + something that can build a fresh one - passing `self._client.fetch()` here would raise + on the second attempt instead of retrying. + + **Only `AppleServiceUnavailableError`, which is a 429 or a 5xx.** Everything else is + either the user's problem or a real fault, and retrying it wastes a person's time + producing the same answer. Apple's own `Retry-After` wins when it sends one, up to + :data:`APPLE_RETRY_CEILING_SECONDS`; past that the refusal is surfaced with the wait + attached, because a screen that silently blocks for a minute is worse than one that + says how long. + + **Never wrap a call that writes.** `join` enrols an escrow record and its own docstring + is explicit that a timeout does not establish that nothing was sent, so a second attempt + can enrol twice. `session.recover` spends one of a capped and unrecoverable number of + passcode attempts - `exporter.icloud.unlock` says the decision to spend another is + always the user's, and that is still true when the caller is a retry loop. Reads only: + opening the client, listing what can be recovered from, resuming, and fetching. + + :param makeCall: Returns a fresh coroutine each time it is called. + :param what: Named in the log, so a retry is visible in a bug report. + """ + attempts = len(APPLE_RETRY_BACKOFF_SECONDS) + 1 + + for attempt in range(attempts): + try: + return self._loop.run_until_complete(makeCall()) + except AppleServiceUnavailableError as refused: + if attempt == attempts - 1: + raise + + wait = refused.retry_after + if wait is None: + wait = APPLE_RETRY_BACKOFF_SECONDS[attempt] + elif wait > APPLE_RETRY_CEILING_SECONDS: + # Apple named a wait longer than anybody should stare at a spinner for. + raise + + print( + f"iCloud bridge: Apple refused {what} with" + f" {refused.status_code}; retrying in {wait}s" + f" ({attempt + 1} of {attempts - 1})") + time.sleep(wait) + + # Unreachable: the last attempt either returns or raises. + raise AssertionError("the retry loop fell through") + def open(self) -> str: """ Open the Find My client, which is a keychain session and a CloudKit client. @@ -347,9 +422,10 @@ def open(self) -> str: return json.dumps({"ok": True}) try: - client = self._loop.run_until_complete( - icloud.open_client(self._async, self._identity)) - self._loop.run_until_complete(client.__aenter__()) + client = self._awaiting( + lambda: icloud.open_client(self._async, self._identity), + "opening the Find My client") + self._awaiting(client.__aenter__, "starting the keychain session") self._client = client return json.dumps({"ok": True}) @@ -375,7 +451,9 @@ def recoveryOptions(self) -> str: return _failure(REASON_NOT_SIGNED_IN, "The Find My client is not open.") try: - options = self._loop.run_until_complete(self._client.recovery_options()) + options = self._awaiting( + self._client.recovery_options, + "asking what this account can be recovered from") except Exception: return _unexpected("asking what this account can be recovered from") @@ -473,7 +551,8 @@ def unlock(self, serial: str, passcode: str) -> str: # is the whole reason this app unlocks at all - so it has to survive the call. peer = self._loop.run_until_complete( self._client.session.recover(record, passcode)) - self._loop.run_until_complete(self._client.resume(peer)) + self._awaiting( + lambda: self._client.resume(peer), "resuming the keychain session") self._sponsor = peer return json.dumps({"ok": True}) @@ -577,7 +656,8 @@ def resume(self, peerJson: str) -> str: try: peer = JoinedPeer.from_json(json.loads(peerJson)) - self._loop.run_until_complete(self._client.resume(peer)) + self._awaiting( + lambda: self._client.resume(peer), "resuming the keychain session") print(f"iCloud bridge: reading as {peer.peer_id}, with no passcode") @@ -611,7 +691,8 @@ def fetch(self) -> str: return _failure(REASON_NOT_SIGNED_IN, "The Find My client is not open.") try: - fetched = self._loop.run_until_complete(icloud.fetch(self._client)) + fetched = self._awaiting( + lambda: icloud.fetch(self._client), "reading the account's accessories") except Exception: return _unexpected("reading the account's accessories") diff --git a/app/src/test/python/requirements.txt b/app/src/test/python/requirements.txt index 68675d1a..b5bdd92a 100644 --- a/app/src/test/python/requirements.txt +++ b/app/src/test/python/requirements.txt @@ -9,7 +9,7 @@ # `FindMy==0.9.8` here for as long as the app built the fork, so every bridge test # ran against a library the app does not ship - which is not a small difference: # the fork's Anisette providers take `serial=` and PyPI's do not. -git+https://github.com/parawanderer/FindMy.py@d956fc8b2679be56b0f4b0053940c5091fc0f1bb +git+https://github.com/parawanderer/FindMy.py@7969003ca785658369b650f75d9e7ca519566bf6 NSKeyedUnArchiver==1.5 PyYAML==6.0.2 diff --git a/app/src/test/python/test_icloud_bridge.py b/app/src/test/python/test_icloud_bridge.py index 97dd87d6..db33aef9 100644 --- a/app/src/test/python/test_icloud_bridge.py +++ b/app/src/test/python/test_icloud_bridge.py @@ -97,6 +97,11 @@ def __init__(self, options=None, unlockError=None) -> None: self.renameError = None self.entered = False self.exited = False + # How many times the next refusable call answers with a refusal before working, and a + # tally of how many times each was actually attempted. Used by the retry tests. + self.refusals = 0 + self.attempts: dict[str, int] = {} + self.retryAfter: float | None = None async def __aenter__(self): self.entered = True @@ -107,8 +112,17 @@ async def __aexit__(self, *_): return False async def recovery_options(self, *, refresh: bool = False): + self._refuseIfTold("recovery_options") return self._options + def _refuseIfTold(self, what: str) -> None: + """Count the attempt, and refuse the first `self.refusals` of them.""" + from findmy.errors import AppleServiceUnavailableError # noqa: PLC0415 + + self.attempts[what] = self.attempts.get(what, 0) + 1 + if self.attempts[what] <= self.refusals: + raise AppleServiceUnavailableError(429, what, self.retryAfter) + # `unlock` recovers explicitly now - `session.recover` then `client.resume` - because the # peer a recovery yields is what sponsors a join, and `client.unlock` keeps it to itself. @property @@ -116,6 +130,7 @@ def session(self): return self async def recover(self, record, passcode): + self._refuseIfTold("recover") self.unlockedWith.append((record.serial, passcode)) if self._unlockError is not None: raise self._unlockError @@ -128,6 +143,7 @@ async def resume(self, peer, **_): return [] async def join(self, peer, *, passcode, device, os_version): + self._refuseIfTold("join") self.joinedWith = SimpleNamespace( peer=peer, passcode=passcode, device=device, os_version=os_version) if self._joinError is not None: @@ -1196,3 +1212,114 @@ def test_something_ordinary_is_still_unknown(self): answer = json.loads(icloud_bridge._unexpected("reading the account's accessories")) assert answer["reason"] == icloud_bridge.REASON_UNKNOWN + + +class TestRefusalsThatClearOnTheirOwn: + """ + Apple refuses the occasional request on a fresh connection and answers the next one. + + Measured in OpenTagViewer#226, and met twice in one sitting on the account-setup screen - + both times cleared by pressing "Try Again". So the app was asking somebody to do by hand, + twice, what it can do in a second. + + **The interesting tests here are the ones about what is *not* retried.** A retry is only + safe on a call that can be made twice, and two of these cannot. + """ + + @pytest.fixture(autouse=True) + def dontActuallyWait(self, monkeypatch): + """Record the waits instead of sleeping them, so the suite stays fast.""" + self.waited: list[float] = [] + monkeypatch.setattr(icloud_bridge.time, "sleep", self.waited.append) + + def test_one_refusal_is_retried_rather_than_shown(self, session): + client = FakeClient() + client.refusals = 1 + made = session(client) + + answer = json.loads(made.recoveryOptions()) + + assert answer["ok"], "a refusal that clears on its own reached the screen" + assert client.attempts["recovery_options"] == 2 + assert self.waited == [1.0] + + def test_it_gives_up_rather_than_retrying_forever(self, session): + # A refusal that does not clear is a real one, and the screen has to say so. The + # September 2026 edge block lasted days; four seconds of patience must not hide it. + client = FakeClient() + client.refusals = 99 + made = session(client) + + answer = json.loads(made.recoveryOptions()) + + assert not answer["ok"] + assert answer["reason"] == icloud_bridge.REASON_APPLE_DECLINED + assert client.attempts["recovery_options"] == 3, "expected two retries, and no more" + assert self.waited == [1.0, 3.0] + + def test_a_wait_apple_names_is_honoured_over_the_backoff(self, session): + client = FakeClient() + client.refusals = 1 + client.retryAfter = 2.5 + made = session(client) + + assert json.loads(made.recoveryOptions())["ok"] + assert self.waited == [2.5], "Apple's own number beats the backoff" + + def test_a_long_wait_is_shown_rather_than_sat_through(self, session): + """ + A header asking for a minute is information for the person, not something to block on. + + Surfaced immediately, with nothing slept, so the screen can say how long. + """ + client = FakeClient() + client.refusals = 1 + client.retryAfter = 600.0 + made = session(client) + + answer = json.loads(made.recoveryOptions()) + + assert not answer["ok"] + assert answer["reason"] == icloud_bridge.REASON_APPLE_DECLINED + assert self.waited == [], "the screen was blocked on a wait Apple asked for" + assert client.attempts["recovery_options"] == 1 + + def test_a_join_is_never_retried(self, session): + """ + **`join` writes.** It enrols an escrow record and adds this app to the trust circle, and + its own docstring says a timeout does not establish that nothing was sent. A second + attempt can therefore enrol a second record - and duplicate records are the noise the + recovery picker already has to filter out. + + So a refusal here reaches the screen on the first one, and the user decides. + """ + client = FakeClient() + made = session(client) + made.recoveryOptions() + assert json.loads(made.unlock("F2LX9Q", "123456"))["ok"] + + client.refusals = 1 + answer = json.loads(made.join("a-generated-passcode")) + + assert not answer["ok"] + assert client.attempts["join"] == 1, "a write was retried" + assert self.waited == [] + + def test_recovering_with_a_passcode_is_never_retried(self, session): + """ + **Escrow attempts are capped, and the cap is unknown.** + + `exporter.icloud.unlock` puts it plainly: the decision to spend another attempt is + always the user's, because exhausting them is not recoverable from here. That stays + true when the thing spending the attempt is a retry loop rather than a person. + """ + client = FakeClient() + made = session(client) + made.recoveryOptions() + + client.refusals = 1 + answer = json.loads(made.unlock("F2LX9Q", "123456")) + + assert not answer["ok"] + assert client.attempts["recover"] == 1, "a capped attempt was spent by a retry" + assert self.waited == [] diff --git a/python/pyproject.toml b/python/pyproject.toml index 4ca2f1fb..008bd213 100644 --- a/python/pyproject.toml +++ b/python/pyproject.toml @@ -69,7 +69,7 @@ constraint-dependencies = [ ] [tool.uv.sources] -FindMy = { git = "https://github.com/parawanderer/FindMy.py", rev = "d956fc8b2679be56b0f4b0053940c5091fc0f1bb" } +FindMy = { git = "https://github.com/parawanderer/FindMy.py", rev = "7969003ca785658369b650f75d9e7ca519566bf6" } [dependency-groups] # Only the release build installs this, with `uv sync --no-default-groups --group build`. It is diff --git a/python/uv.lock b/python/uv.lock index 09511c48..63728cc2 100644 --- a/python/uv.lock +++ b/python/uv.lock @@ -659,7 +659,7 @@ wheels = [ [[package]] name = "findmy" version = "0.10.1" -source = { git = "https://github.com/parawanderer/FindMy.py?rev=d956fc8b2679be56b0f4b0053940c5091fc0f1bb#d956fc8b2679be56b0f4b0053940c5091fc0f1bb" } +source = { git = "https://github.com/parawanderer/FindMy.py?rev=7969003ca785658369b650f75d9e7ca519566bf6#7969003ca785658369b650f75d9e7ca519566bf6" } dependencies = [ { name = "aiohttp" }, { name = "anisette" }, @@ -1032,7 +1032,7 @@ dev = [ [package.metadata] requires-dist = [ - { name = "findmy", git = "https://github.com/parawanderer/FindMy.py?rev=d956fc8b2679be56b0f4b0053940c5091fc0f1bb" }, + { name = "findmy", git = "https://github.com/parawanderer/FindMy.py?rev=7969003ca785658369b650f75d9e7ca519566bf6" }, { name = "pycryptodome", specifier = "==3.22.0" }, { name = "pyyaml", specifier = "==6.0.2" }, { name = "pyzipper", specifier = "==0.4.0" },