diff --git a/README.md b/README.md index 99e435e..d2a522c 100644 --- a/README.md +++ b/README.md @@ -47,6 +47,10 @@ Make the credential files `chmod 600`. The first run downloads about 4800 photos, one Flickr info call and one sizes call each, so at the default one-second pace it takes a few hours. The pace applies to Flickr alone; Immich and the wiki index are not slowed. +A 429 from Flickr doubles the pace for the rest of the run, up to ten seconds +between calls, and it relaxes again after twenty untroubled requests. The +photo that hit the limit is retried with backoff starting at fifteen seconds +and doubling, up to eight attempts. Later runs skip everything already on disk, and in Immich only write an album membership or a description that has actually changed. @@ -140,8 +144,8 @@ A flag beats the environment, which beats the file, which beats the default. | `limit` | `--limit N` | | unlimited | | `pace` | `--pace SECONDS` | `RGL_PHOTO_BACKUP_PACE` | `1` | | `quiet` | `--quiet`, `-q` | | `false` | -| `attempts` | | `RGL_PHOTO_BACKUP_ATTEMPTS` | `6` | -| `backoff` | | `RGL_PHOTO_BACKUP_BACKOFF` | `5` | +| `attempts` | | `RGL_PHOTO_BACKUP_ATTEMPTS` | `8` | +| `backoff` | | `RGL_PHOTO_BACKUP_BACKOFF` | `15` | | `timeout` | | `RGL_PHOTO_BACKUP_TIMEOUT` | `60` | | `user_agent` | | `RGL_PHOTO_BACKUP_USER_AGENT` | `rgl-photo-backup/1.0` | | `debug` | `--debug` | `RGL_PHOTO_BACKUP_DEBUG` | `false` | diff --git a/rgl-photo-backup b/rgl-photo-backup index db6b509..cd29c38 100755 --- a/rgl-photo-backup +++ b/rgl-photo-backup @@ -44,7 +44,9 @@ BATCH = 500 # ids per album/tag write CHUNK = 1024 * 1024 # hashing DOWNLOAD_CHUNK = 256 * 1024 DOWNLOAD_CAP = 100 * 1024 * 1024 # no wiki photo is this big; something is wrong -BACKOFF_CAP = 300.0 +BACKOFF_CAP = 900.0 +PACE_CAP = 10.0 # slowest a 429 storm can make flickr calls +PACE_HOLD = 20 # untroubled requests before the pace relaxes ENV = "RGL_PHOTO_BACKUP_" @@ -60,8 +62,8 @@ DEFAULTS = { "limit": None, "pace": 1.0, "quiet": False, - "attempts": 6, - "backoff": 5.0, + "attempts": 8, + "backoff": 15.0, "timeout": 60.0, "user_agent": "rgl-photo-backup/1.0", "debug": False, @@ -72,6 +74,8 @@ USER_AGENT = os.environ.get(ENV + "USER_AGENT", DEFAULTS["user_agent"]) ATTEMPTS = int(os.environ.get(ENV + "ATTEMPTS", DEFAULTS["attempts"])) BACKOFF_BASE = float(os.environ.get(ENV + "BACKOFF", DEFAULTS["backoff"])) PACE = float(os.environ.get(ENV + "PACE", DEFAULTS["pace"])) +PACE_FLOOR = PACE # the configured pace; PACE rises above it after a 429 +PACEHELD = 0 DEBUG = bool(os.environ.get(ENV + "DEBUG")) QUIET = False @@ -303,9 +307,12 @@ def backoff(attempt): # failures. consume() is handed the open response so a body can be read into # memory or streamed to disk under one retry policy. 429 and 5xx are worth # another go; any other 4xx is our fault and will not improve. Only flickr -# needs pacing, and only flickr's limit is worth slowing the run for. +# needs pacing, and only flickr's limit is worth slowing the run for: a 429 +# there is an hourly window, which no single photo's backoff can wait out, so +# it slows every later paced request and relaxes only after a quiet spell. # def retrying(url, context, consume, headers=None, data=None, method="GET", pace=False): + global PACE, PACEHELD sent = {"User-Agent": USER_AGENT} sent.update(headers or {}) for attempt in range(1, ATTEMPTS + 1): @@ -317,7 +324,7 @@ def retrying(url, context, consume, headers=None, data=None, method="GET", pace= try: response = OPEN(request, timeout=HTTP_TIMEOUT) try: - return consume(response) + result = consume(response) finally: response.close() except BackupError: @@ -332,6 +339,10 @@ def retrying(url, context, consume, headers=None, data=None, method="GET", pace= e.close() raise HTTPFailure("%s: HTTP %s %s%s" % (context, e.code, e.reason, detail), code=e.code) + if e.code == 429 and pace: + PACE = min(max(PACE * 2, 1.0), PACE_CAP) + PACEHELD = PACE_HOLD + warn("%s: rate limited, pacing flickr requests %.1fs apart" % (context, PACE)) wait = retryafter(e) reason = "HTTP %s %s" % (e.code, e.reason) code = e.code @@ -340,6 +351,13 @@ def retrying(url, context, consume, headers=None, data=None, method="GET", pace= wait = None reason = "%s: %s" % (type(e).__name__, e) code = None + else: + if pace and PACE > PACE_FLOOR: + if PACEHELD > 0: + PACEHELD -= 1 + else: + PACE = max(PACE_FLOOR, PACE * 0.9) + return result if attempt == ATTEMPTS: raise HTTPFailure("%s: giving up after %d attempts (%s)" @@ -1279,8 +1297,9 @@ def syncphase(conf, immich): def applysettings(conf): - global PACE, ATTEMPTS, BACKOFF_BASE, HTTP_TIMEOUT, USER_AGENT, QUIET, DEBUG - PACE = float(conf["pace"]) + global PACE, PACE_FLOOR, PACEHELD, ATTEMPTS, BACKOFF_BASE, HTTP_TIMEOUT, USER_AGENT, QUIET, DEBUG + PACE = PACE_FLOOR = float(conf["pace"]) + PACEHELD = 0 ATTEMPTS = int(conf["attempts"]) BACKOFF_BASE = float(conf["backoff"]) HTTP_TIMEOUT = float(conf["timeout"]) diff --git a/test_rgl_photo_backup.py b/test_rgl_photo_backup.py index dfe4fd8..67d8143 100644 --- a/test_rgl_photo_backup.py +++ b/test_rgl_photo_backup.py @@ -74,8 +74,9 @@ class FakeOpen: class TestCase(unittest.TestCase): """Silences output and restores the module globals tests move around.""" - GLOBALS = ("OPEN", "SLEEP", "ATTEMPTS", "BACKOFF_BASE", "PACE", "QUIET", - "DEBUG", "HTTP_TIMEOUT", "USER_AGENT", "STATS", "DOWNLOAD_CAP") + GLOBALS = ("OPEN", "SLEEP", "ATTEMPTS", "BACKOFF_BASE", "PACE", "PACE_FLOOR", + "PACEHELD", "QUIET", "DEBUG", "HTTP_TIMEOUT", "USER_AGENT", "STATS", + "DOWNLOAD_CAP") def setUp(self): self._output = contextlib.ExitStack() @@ -87,7 +88,8 @@ class TestCase(unittest.TestCase): self.addCleanup(self._output.close) self._saved = {k: getattr(rb, k) for k in self.GLOBALS} rb.SLEEP = lambda seconds: None - rb.PACE = 0.0 + rb.PACE = rb.PACE_FLOOR = 0.0 + rb.PACEHELD = 0 rb.STATS = dict.fromkeys(rb.STATS, 0) self.tmp = tempfile.TemporaryDirectory() self.addCleanup(self.tmp.cleanup) @@ -309,7 +311,9 @@ class Settings(TestCase): self.assertTrue(conf["fetch"] and conf["sync"]) self.assertFalse(conf["dry_run"]) self.assertIsNone(conf["limit"]) - self.assertEqual(conf["attempts"], 6) + self.assertEqual(conf["attempts"], 8) + self.assertEqual(conf["backoff"], 15.0) + self.assertEqual(rb.BACKOFF_CAP, 900.0) self.assertEqual(conf["flickr_auth"], os.path.expanduser(rb.FLICKR_CONFIG)) def test_defaults_are_literals_not_moving_constants(self): @@ -319,7 +323,7 @@ class Settings(TestCase): self.assertEqual(conf["pace"], rb.DEFAULTS["pace"]) self.assertEqual(conf["attempts"], rb.DEFAULTS["attempts"]) self.assertEqual(conf["user_agent"], rb.DEFAULTS["user_agent"]) - self.assertEqual((rb.DEFAULTS["pace"], rb.DEFAULTS["attempts"]), (1.0, 6)) + self.assertEqual((rb.DEFAULTS["pace"], rb.DEFAULTS["attempts"]), (1.0, 8)) def test_debug_is_a_setting(self): path = self.write("s.yml", "directory: /d\ndebug: true\n") @@ -430,6 +434,39 @@ class Retrying(TestCase): rb.flickrcall("flickr.test.echo", {}, "KEY") self.assertEqual(waits, [2.0]) + def test_429_slows_every_later_flickr_call(self): + waits = [] + rb.SLEEP = waits.append + rb.PACE = rb.PACE_FLOOR = 1.0 + rb.OPEN = FakeOpen(http_error(429), FakeResponse({"stat": "ok"}), + FakeResponse({"stat": "ok"})) + rb.flickrcall("flickr.test.echo", {}, "KEY") + self.assertEqual(rb.PACE, 2.0) + rb.flickrcall("flickr.test.echo", {}, "KEY") + self.assertEqual(waits[-1], 2.0) + self.assertEqual(rb.PACEHELD, rb.PACE_HOLD - 2) + self.assertIn("pacing", self.stderr.getvalue()) + + def test_pace_relaxes_back_to_the_configured_floor(self): + rb.PACE_FLOOR = 1.0 + rb.PACE = 4.0 + rb.OPEN = FakeOpen(*[FakeResponse({"stat": "ok"}) for _ in range(40)]) + for _ in range(40): + rb.flickrcall("flickr.test.echo", {}, "KEY") + self.assertEqual(rb.PACE, 1.0) + + def test_pace_never_exceeds_the_cap(self): + rb.PACE = rb.PACE_FLOOR = 8.0 + rb.OPEN = FakeOpen(http_error(429), FakeResponse({"stat": "ok"})) + rb.flickrcall("flickr.test.echo", {}, "KEY") + self.assertEqual(rb.PACE, rb.PACE_CAP) + + def test_429_from_immich_leaves_the_pace_alone(self): + rb.PACE = rb.PACE_FLOOR = 1.0 + rb.OPEN = FakeOpen(http_error(429), FakeResponse({"id": "u1"})) + rb.Immich("https://i/api", "k").me() + self.assertEqual(rb.PACE, 1.0) + def test_pace_leaves_immich_and_the_index_alone(self): waits = [] rb.SLEEP = waits.append