Hold repeated update checks back, and say when GitHub takes them again.

Every selection of the Updates row started a request to GitHub, which
allows an address 60 an hour: a player who selected it 25 times in 90
seconds had every check of the next hour refused. The row and F5 now
start no check within a minute of the last one.

A refused check said "try again in an hour" whatever the answer held. It
now names the time from the answer's X-RateLimit-Reset or Retry-After.
A failed check wrote two tracebacks, 22 lines, into launcher.log each
time; a FeedError is now one line with its message and its cause.

Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>

docs/launcher.md

@@ -174,6 +174,10 @@ directly. Every address is https (plain http only to this PC), a redirect to htt
 sent on when a redirect leaves the host it was meant for (`launcher/net.py`). A manifest that does not give a file's
 size and sha256 is refused.
 
+GitHub allows an address 60 such requests an hour. The Updates row and F5 therefore start no check within a minute
+of the last one (`FORCED_CHECK_PAUSE`), and a check GitHub refuses says when the allowance is whole again, from the
+answer's `X-RateLimit-Reset` (`feed.retry_text`). A failed check is one line in `launcher.log`.
+
 ### In the background
 
 The player never waits for a download and play is never interrupted. A check that finds a newer release (the check

launcher/feed.py

@@ -14,6 +14,7 @@ The feed (app/<version>/feed.json, or the player's override in settings) is eith
 """
 import json
 import re
+import time
 import urllib.parse
 from pathlib import Path
 
@@ -78,6 +79,30 @@ def _check_manifest(m, where):
     return m
 
 
+def retry_text(headers, now=None):
+    """When GitHub takes requests again, for the message of a refused one: "after 14:32 (in 25 minutes)". From
+    X-RateLimit-Reset, the time the hourly allowance is whole again, when the response says the allowance is used
+    up (X-RateLimit-Remaining: 0), else from Retry-After, the seconds to wait. '' when the response says neither
+    or says something that cannot be right (more than a day)."""
+    now = time.time() if now is None else now
+    try:
+        if headers.get('X-RateLimit-Remaining') == '0' and headers.get('X-RateLimit-Reset'):
+            wait = int(headers.get('X-RateLimit-Reset')) - now
+        elif headers.get('Retry-After'):
+            wait = int(headers.get('Retry-After'))
+        else:
+            return ''
+    except (AttributeError, TypeError, ValueError):
+        return ''
+    if wait > 86400:
+        return ''
+    if wait <= 0:   # the allowance is whole again by this PC's clock
+        return 'in a minute'
+    minutes = int(-(-wait // 60))
+    return (f'after {time.strftime("%H:%M", time.localtime(now + wait))} '
+            f'(in {minutes} minute{"" if minutes == 1 else "s"})')
+
+
 def _github(feed, channel, token, version):
     api = feed.get('api', GITHUB_API).rstrip('/')
     headers = {'Accept': 'application/vnd.github+json', 'X-GitHub-Api-Version': '2022-11-28'}
@@ -89,8 +114,9 @@ def _github(feed, channel, token, version):
         code = getattr(e, 'code', None)
         if code == 404:
             raise FeedError(f'no releases found for {feed["repo"]} (a private repository needs a token)') from e
-        if code == 403:
-            raise FeedError('GitHub refused the request (rate limit); try again in an hour') from e
+        if code in (403, 429):   # GitHub answers either when the allowance of requests is used up
+            when = retry_text(getattr(e, 'headers', None))
+            raise FeedError(f'GitHub refused the request (rate limit); try again {when or "in an hour"}') from e
         raise FeedError(f'GitHub could not be reached: {e}') from e
     # The API lists the newest release first: the first one the channel takes that has a manifest is the answer.
     for r in releases:

launcher/jobs.py

@@ -13,6 +13,16 @@ RECHECK = 3600   # seconds between update checks while the launcher stays open,
 
 PENDING, RUNNING, DONE, SKIPPED, FAILED = 'pending', 'running', 'done', 'skipped', 'failed'
 
+# Failures whose message says all there is to say: the log gets one line for them (failure_line), not a traceback.
+# A refused update check wrote 22 lines of two tracebacks into launcher.log each time.
+PLAIN_FAILURES = (feed.FeedError,)
+
+
+def failure_line(e):
+    """A failure in one line for the log: its kind, its message and what it came from."""
+    cause = e.__cause__
+    return f'{type(e).__name__}: {e}' + (f' ({type(cause).__name__}: {cause})' if cause else '')
+
 STEPS = {
     'tools': ('Gather Build Tools', 'Downloading the compiler and libraries the build uses. This happens once and '
                                     'takes about 170 MB.'),
@@ -230,7 +240,7 @@ class Job:
                 self.result = 'cancelled'
             else:
                 self.result, self.error = 'failed', str(e) or type(e).__name__
-                self.ctx.log(traceback.format_exc())
+                self.ctx.log(failure_line(e) if isinstance(e, PLAIN_FAILURES) else traceback.format_exc())
         finally:
             for s in self.steps:
                 if s.state == RUNNING:

launcher/ui/app.py

@@ -184,6 +184,11 @@ def drop_partial_image(game_dir):
         pass
 
 
+# Seconds after an update check before the Updates row or F5 starts another. Each check is a request to GitHub,
+# which allows 60 an hour for an address: a player who selected the row 25 times in 90 seconds used the allowance
+# up, and every check of the next hour was refused.
+FORCED_CHECK_PAUSE = 60
+
 # How long an update's rebuild takes, for the Updates row. No single figure holds: a version that changed little
 # compiles a few files and links, minutes; one that changed the lifter translates and compiles the game's code again,
 # and one that changed what the shaders are built with builds all of them into the graphics driver's cache again
@@ -1312,6 +1317,11 @@ class App:
             return
         if not force and time.time() - self.settings.get('last_check', 0) < 600 and self.release:
             return
+        if force and time.time() - self.check_started < FORCED_CHECK_PAUSE:
+            self.message = 'NX2navi looked for updates less than a minute ago.'
+            if self.screen == 'home':
+                self.show('home', self.focus)
+            return
         self.check_error = ''
         self.check_started = time.time()
         self.check = jobs.CheckJob(self.ctx).start()

tests/launcher_test.py

@@ -719,6 +719,63 @@ class FeedTest(Tmp):
         self.assertTrue(any(h.get('Authorization') == 'Bearer secret' for _, h in srv.hits))
         self.assertEqual(feed.plain_notes('## Head\n- **One**\n* `Two`\n<!-- x -->'), ['Head', 'One', 'Two'])
 
+    def test_a_refused_check_says_when_to_try_again(self):
+        """GitHub's answer to a request over the hourly allowance carries the time the allowance is whole again:
+        the message names it, and the log gets one line for the failed check, not two tracebacks."""
+        srv = self.serve_github()
+        reset = int(time.time()) + 1500
+        self.routes['/repos/o/r/releases?per_page=20'] = (
+            403, {'X-RateLimit-Remaining': '0', 'X-RateLimit-Reset': str(reset)}, b'{"message": "rate limit"}')
+        f = {'type': 'github', 'repo': 'o/r', 'api': srv.url.rstrip('/')}
+        with self.assertRaises(feed.FeedError) as c:
+            feed.latest(f, 'stable')
+        at = time.strftime('%H:%M', time.localtime(reset))
+        self.assertRegex(str(c.exception), rf'^GitHub refused the request \(rate limit\); try again after {at} '
+                                           r'\(in 2[45] minutes\)$')
+        # the header's forms
+        now = 1700000000
+        text = feed.retry_text
+        self.assertTrue(text({'X-RateLimit-Remaining': '0', 'X-RateLimit-Reset': str(now + 61)}, now)
+                        .endswith(' (in 2 minutes)'))
+        self.assertTrue(text({'X-RateLimit-Remaining': '0', 'X-RateLimit-Reset': str(now + 60)}, now)
+                        .endswith(' (in 1 minute)'))
+        self.assertEqual(text({'X-RateLimit-Remaining': '0', 'X-RateLimit-Reset': str(now - 5)}, now), 'in a minute')
+        self.assertTrue(text({'Retry-After': '120'}, now).endswith(' (in 2 minutes)'))
+        self.assertTrue(text({'Retry-After': '120'}, now).startswith('after '))
+        self.assertEqual(text({'X-RateLimit-Remaining': '12', 'X-RateLimit-Reset': str(now + 600)}, now), '')
+        for nothing in ({}, None, {'X-RateLimit-Remaining': '0', 'X-RateLimit-Reset': 'soon'},
+                        {'X-RateLimit-Remaining': '0', 'X-RateLimit-Reset': str(now + 10 ** 6)}):
+            self.assertEqual(text(nothing, now), '')
+        # a refusal without the headers keeps the old advice
+        self.routes['/repos/o/r/releases?per_page=20'] = (403, {}, b'{}')
+        with self.assertRaises(feed.FeedError) as c:
+            feed.latest(f, 'stable')
+        self.assertEqual(str(c.exception), 'GitHub refused the request (rate limit); try again in an hour')
+        # the job: one line in the log
+        ctx = Context(self.layout)
+        self.addCleanup(ctx._file.close)
+        ctx.settings['feed_repo'] = 'o/r'
+        with mock.patch.object(feed, 'GITHUB_API', srv.url.rstrip('/')):
+            j = jobs.CheckJob(ctx).run_inline()
+        self.assertEqual((j.result, j.error), ('failed', 'GitHub refused the request (rate limit); try again in an hour'))
+        ctx._file.flush()
+        log = (self.layout.logs / 'launcher.log').read_text(encoding='utf-8').splitlines()[1:]
+        self.assertEqual(len(log), 1, log)
+        self.assertIn('FeedError: GitHub refused the request (rate limit); try again in an hour (HTTPError: HTTP Error '
+                      '403', log[0])
+        self.assertNotIn('Traceback', log[0])
+
+    def test_other_failures_keep_their_traceback(self):
+        ctx = Context(self.layout)
+        self.addCleanup(ctx._file.close)
+        j = jobs.Job(ctx, [])
+        j.run = lambda: [][1]
+        j.run_inline()
+        ctx._file.flush()
+        log = (self.layout.logs / 'launcher.log').read_text(encoding='utf-8')
+        self.assertIn('Traceback (most recent call last)', log)
+        self.assertIn('IndexError', log)
+
     def test_url_feed_and_update(self):
         z = make_app_zip(self.tmp, '0.9.0')
         (self.tmp / feed.MANIFEST).write_text(json.dumps(manifest_for(z, '0.9.0')))
@@ -3732,6 +3789,29 @@ class UpdateTextTest(Tmp):
         self.assertIn('half an hour or more', app.UPDATE_TAKES)
 
 
+class ForcedCheckTest(Tmp):
+    def test_one_forced_update_check_a_minute(self):
+        """Selecting the Updates row (or F5) again within a minute of the last check starts no request: 25 of them
+        in 90 seconds used up GitHub's hourly allowance for a player."""
+        from launcher.ui import app
+        App, a = mock_app(self, self.tmp / 'game')
+        a.screen = 'home'
+        with mock.patch('launcher.ui.app.jobs.CheckJob') as check:
+            a.check_started = time.time() - 10
+            App.check_now(a, force=True)
+            check.assert_not_called()
+            self.assertEqual(a.message, 'NX2navi looked for updates less than a minute ago.')
+            a.show.assert_called_once_with('home', a.focus)
+            a.check_started = time.time() - app.FORCED_CHECK_PAUSE - 1
+            App.check_now(a, force=True)
+            check.assert_called_once()
+            self.assertGreater(a.check_started, time.time() - 5)
+            # the launcher's own checks (at start, every hour) are not held back by it
+            a.check, a.check_started = None, time.time() - 10
+            App.check_now(a)
+            self.assertEqual(check.call_count, 2)
+
+
 class StartScriptTest(Tmp):
     """launcher/start.pyw when the version cannot be imported: with a version to go back to it ends with code 86 at
     once and shows no message box, so the stub's six-second wait sees the code and rolls back."""