chore(release): v0.2.3

Reviewed-on: #4

README.md

@@ -44,12 +44,47 @@ deletes music.
 
 ### Indexing quirks
 
-Albums are fetched from the **unfiltered** `GET /api/v1/album`, not one call per
+Albums are fetched from the **unfiltered** `GET /api/v1/album` first: one
-artist. `?artistId=` is Lidarr's unguarded path: it dereferences the album's
+request, and the only path that skips albums whose artist metadata is missing
-artist metadata with no null check and picks the monitored release with
+rather than dereferencing it.
-`SingleOrDefault`, so it returns a 500 for an album with broken metadata or two
+
-monitored releases. The unfiltered endpoint skips such albums instead, and costs
+That is not enough on its own. Every album endpoint maps through a resource
-N fewer requests.
+that picks the release with `SingleOrDefault(x => x.Monitored)`, which throws
+for an album with **two monitored releases** and takes the whole response with
+it:
+
+```
+HTTP 500: Sequence contains more than one element
+```
+
+When the bulk call dies that way, the indexer falls back to one request per
+artist. It cannot avoid the exception, but it confines it to whichever artist
+owns the offending album and names them in the log — which is the only
+practical way to find it in a large library. Open that artist in Lidarr and
+check the Releases tab of each album: exactly one release may be monitored.
+
+Losing an artist's albums does not cost their tracks, which come from a
+different endpoint with a different mapper, so matching is unaffected. A cull
+would not be, and the report says so.
+
+### Talking to Lidarr
+
+Indexing is two requests per artist, and more when the album fallback fires. On
+a large library that is thousands of requests in a few minutes. `urllib` opens a
+new TCP connection and performs a new DNS lookup for every one of them, which is
+enough to exhaust a container's resolver and produce `[Errno -3] Try again` on
+everything at once. The client therefore holds one connection open per host and
+resolves once.
+
+Transient failures — a dropped connection, a resolver hiccup, `429`, `502`,
+`503`, `504` — are retried with a backoff. An HTTP `500` is not: it is an
+unhandled exception inside Lidarr's own serialisation and will be raised again
+identically. That distinction also decides whether a failure is worth
+investigating; a library-wide outage is not probed artist by artist, because
+doing so multiplies the load that caused it.
+
+A local address is preferable to a public hostname here. It removes DNS, the
+reverse proxy and its timeouts from a path that needs none of them.
 
 Tracks and files have no unfiltered endpoint — Lidarr rejects a call with no
 filter — so they stay per artist. If one artist cannot be served, that artist is

music_curator.py

@@ -17,6 +17,8 @@ cursor, so an interrupted run resumes from what it actually has.
 
 import argparse
 import fcntl
+import http.client
+import io
 import json
 import logging
 import os
@@ -48,6 +50,11 @@ PAGE_SIZE = 200
 RETRYABLE_ERRORS = {8, 11, 16, 29}
 RETRYABLE_STATUS = {429, 500, 502, 503, 504}
 
+# Lidarr's own list, and 500 is deliberately absent. A 500 from Lidarr is an
+# unhandled exception inside its serialisation, not a busy server; it will be
+# raised again identically, and retrying only delays finding that out.
+LIDARR_RETRYABLE_STATUS = {429, 502, 503, 504}
+
 # Last.fm asks for no more than five requests a second averaged over five
 # minutes. A full backfill is thousands of requests, so it is worth staying
 # well inside that rather than discovering error 29 halfway through.
@@ -207,7 +214,18 @@ class LastfmError(Exception):
 
 
 class LidarrError(Exception):
-    """A Lidarr request that failed."""
+    """A Lidarr request that failed.
+
+    `transient` separates "the network or the server had a moment" from "this
+    request will fail identically forever". The distinction matters twice: only
+    the first is worth retrying, and only the second is worth investigating,
+    since probing a library-wide outage artist by artist multiplies the load
+    that caused it.
+    """
+
+    def __init__(self, message, transient=False):
+        super().__init__(message)
+        self.transient = transient
 
 
 def normalise(text):
@@ -645,34 +663,118 @@ def sync_loved(client, store, user):
     return len(rows)
 
 
+class KeepAlive:
+    """A transport that holds one connection open per host.
+
+    urllib opens a fresh TCP connection -- and performs a fresh DNS lookup --
+    for every request it makes. Indexing a library is two requests per artist,
+    which on a large collection is thousands of lookups inside a few minutes.
+    That is enough to exhaust a container's resolver, and the failure it
+    produces is `[Errno -3] Try again` on everything at once. Resolving once and
+    reusing the socket removes the cause rather than papering over it, and is
+    considerably faster besides.
+    """
+
+    def __init__(self, timeout=60):
+        self.timeout = timeout
+        self._connections = {}
+
+    def __call__(self, url, timeout=None, headers=None):
+        parsed = urllib.parse.urlparse(url)
+        key = (parsed.scheme, parsed.hostname, parsed.port)
+        target = parsed.path + (f"?{parsed.query}" if parsed.query else "")
+        request_headers = {**(headers or {}), "Accept": "application/json"}
+
+        # Two attempts, because a kept-alive connection the server has since
+        # closed fails on use rather than announcing itself. The second attempt
+        # is on a fresh socket.
+        for attempt in (1, 2):
+            connection = self._connections.get(key)
+            if connection is None:
+                connection = self._connect(parsed, timeout or self.timeout)
+                self._connections[key] = connection
+            try:
+                connection.request("GET", target, headers=request_headers)
+                response = connection.getresponse()
+                body = response.read()
+            except (http.client.HTTPException, OSError) as error:
+                self.close(key)
+                if attempt == 2:
+                    raise urllib.error.URLError(error) from error
+                continue
+
+            if response.status >= 300:
+                # Includes redirects: this client does not follow them, and one
+                # here means the URL is pointing somewhere unintended.
+                raise urllib.error.HTTPError(
+                    url, response.status, response.reason, response.headers, io.BytesIO(body)
+                )
+            return body.decode("utf-8")
+        raise urllib.error.URLError("unreachable")
+
+    @staticmethod
+    def _connect(parsed, timeout):
+        if parsed.scheme == "https":
+            return http.client.HTTPSConnection(parsed.hostname, parsed.port, timeout=timeout)
+        return http.client.HTTPConnection(parsed.hostname, parsed.port, timeout=timeout)
+
+    def close(self, key=None):
+        for handle in [self._connections.pop(key, None)] if key else self._connections.values():
+            if handle is not None:
+                handle.close()
+        if key is None:
+            self._connections.clear()
+
+
 class Lidarr:
     """Minimal read-only Lidarr client.
 
-    No retries: Lidarr is on the same LAN as this, and a failure there means it
+    Retries only what is worth retrying. A dropped connection or a resolver
-    is down or the key is wrong, neither of which improves on a second attempt.
+    hiccup is transient; an HTTP 500 out of Lidarr is an exception in its own
+    serialisation and will be thrown again identically, so spending three
+    attempts on it only slows down finding out.
     """
 
-    def __init__(self, url, api_key, timeout=60, transport=None):
+    def __init__(self, url, api_key, timeout=60, attempts=3, backoff=1.0, transport=None):
         self.root = url.rstrip("/")
         self.api_key = api_key
         self.timeout = timeout
-        self.transport = transport or http_get
+        self.attempts = attempts
+        self.backoff = backoff
+        self.transport = transport or KeepAlive(timeout)
 
     def get(self, path, params=None):
         """Return the decoded response for one API path."""
         query = urllib.parse.urlencode(params or {})
         url = f"{self.root}/api/v1/{path}" + (f"?{query}" if query else "")
-        try:
+
-            body = self.transport(url, timeout=self.timeout, headers={"X-Api-Key": self.api_key})
+        for attempt in range(1, self.attempts + 1):
-        except urllib.error.HTTPError as error:
+            try:
-            detail = error_detail(error)
+                body = self.transport(
-            raise LidarrError(f"GET {url}: HTTP {error.code}{': ' + detail if detail else ''}")
+                    url, timeout=self.timeout, headers={"X-Api-Key": self.api_key}
-        except (urllib.error.URLError, TimeoutError) as error:
+                )
-            raise LidarrError(f"GET {url}: {error}") from error
+            except urllib.error.HTTPError as error:
-        try:
+                detail = error_detail(error)
-            return json.loads(body)
+                message = f"GET {url}: HTTP {error.code}{': ' + detail if detail else ''}"
-        except json.JSONDecodeError as error:
+                if error.code not in LIDARR_RETRYABLE_STATUS:
-            raise LidarrError(f"GET {url}: malformed response") from error
+                    raise LidarrError(message)
+                if attempt >= self.attempts:
+                    raise LidarrError(message, transient=True)
+            except (urllib.error.URLError, TimeoutError) as error:
+                message = f"GET {url}: {error}"
+                if attempt >= self.attempts:
+                    raise LidarrError(message, transient=True) from error
+            else:
+                try:
+                    return json.loads(body)
+                except json.JSONDecodeError as error:
+                    raise LidarrError(f"GET {url}: malformed response") from error
+
+            pause = min(self.backoff * 2 ** (attempt - 1), BACKOFF_CEILING_SECONDS)
+            logger.warning("%s; retrying in %.0fs", message, pause)
+            time.sleep(pause)
+
+        raise LidarrError(f"GET {url}: gave up after {self.attempts} attempts", transient=True)
 
 
 def error_detail(error, limit=300):
@@ -707,6 +809,82 @@ def parse_added(value):
         return None
 
 
+def find_bad_albums(client, artist_id, artist_name):
+    """Name the specific albums Lidarr cannot serialise for one artist.
+
+    Runs only once that artist's album fetch has already failed, so the extra
+    requests are spent on a problem that already exists. Tracks come from an
+    endpoint that still works, and their album ids give a list to probe one at a
+    time; the ones that throw are the culprits. A track title from each is
+    enough to recognise the album in the UI, which the id alone is not.
+    """
+    try:
+        tracks = client.get("track", {"artistId": artist_id})
+    except LidarrError as error:
+        logger.warning("could not probe %s for the offending album: %s", artist_name, error)
+        return []
+
+    sample = {}
+    for track in tracks:
+        sample.setdefault(track.get("albumId"), track.get("title") or "")
+
+    bad = []
+    for album_id, title in sorted(sample.items(), key=lambda item: item[0] or 0):
+        if not album_id:
+            continue
+        try:
+            client.get("album", {"albumIds": album_id})
+        except LidarrError:
+            bad.append((album_id, title))
+    return bad
+
+
+def fetch_albums(client, artists):
+    """Return albums grouped by artist id, plus the artists whose albums failed.
+
+    Every album endpoint maps through a resource that picks the release with
+    `SingleOrDefault(x => x.Monitored)`, which throws for an album with two
+    monitored releases -- "Sequence contains more than one element" -- and takes
+    the entire response down with it.
+
+    The unfiltered endpoint is one request and is the only one that also skips
+    albums whose artist metadata is missing, so it is tried first. When it dies,
+    asking per artist confines the loss to whichever artist owns the offending
+    album, and names them, which is the only way to find it.
+    """
+    try:
+        grouped = {}
+        for album in client.get("album"):
+            grouped.setdefault(album.get("artistId"), []).append(album)
+        return grouped, []
+    except LidarrError as error:
+        logger.warning("fetching all albums failed (%s)", error)
+        logger.warning("falling back to one request per artist to isolate the bad album")
+
+    grouped, failed = {}, []
+    for artist in artists:
+        artist_id = artist["id"]
+        try:
+            grouped[artist_id] = client.get("album", {"artistId": artist_id})
+        except LidarrError as error:
+            name = artist.get("artistName") or str(artist_id)
+            logger.warning("could not fetch albums for %s: %s", name, error)
+            failed.append(name)
+            # Only worth probing a deterministic failure. When the network or
+            # the resolver is the problem, every artist fails, and probing each
+            # of them album by album multiplies the load that caused it.
+            if not error.transient:
+                for album_id, sample in find_bad_albums(client, artist_id, name):
+                    logger.warning(
+                        "  album id %d is the one Lidarr cannot serialise (it holds the"
+                        " track %r). Open it in Lidarr and leave exactly one release"
+                        " monitored.",
+                        album_id,
+                        sample,
+                    )
+    return grouped, failed
+
+
 def index_library(client, store):
     """Rebuild the library index from Lidarr. Returns (artists, tracks).
 
@@ -718,13 +896,7 @@ def index_library(client, store):
     artist_rows, album_rows, track_rows = [], [], []
     skipped = []
 
-    # Albums come back in one unfiltered call rather than one per artist. That
+    albums_by_artist, album_failures = fetch_albums(client, artists)
-    # endpoint is the only one Lidarr hydrates defensively -- it skips an album
-    # whose artist metadata is missing, where `?artistId=` dereferences it and
-    # returns a 500 -- and it costs N fewer requests into the bargain.
-    albums_by_artist = {}
-    for album in client.get("album"):
-        albums_by_artist.setdefault(album.get("artistId"), []).append(album)
 
     for artist in artists:
         artist_id = artist["id"]
@@ -790,6 +962,7 @@ def index_library(client, store):
 
     store.replace_library(artist_rows, album_rows, track_rows)
     store.set_state("index_skipped", str(len(skipped)))
+    store.set_state("index_albums_skipped", str(len(album_failures)))
     logger.info(
         "library indexed: %d artists, %d albums, %d tracks (%d with files)",
         len(artist_rows),
@@ -803,6 +976,14 @@ def index_library(client, store):
             len(skipped),
             ", ".join(sorted(skipped)[:10]),
         )
+    if album_failures:
+        logger.warning(
+            "no albums indexed for %d artists: %s."
+            " In Lidarr, open each one and check the Releases tab of their albums:"
+            " exactly one release per album may be monitored.",
+            len(album_failures),
+            ", ".join(sorted(album_failures)[:10]),
+        )
     return len(artist_rows), len(track_rows)
 
 
@@ -876,6 +1057,13 @@ def coverage_report(store):
             " figure below is a floor. Do not cull against it.",
             skipped,
         )
+    albums_skipped = int(store.get_state("index_albums_skipped") or 0)
+    if albums_skipped:
+        logger.warning(
+            "%d artists have no albums indexed. Matching is unaffected -- it runs off"
+            " tracks -- but a cull cannot be run until this is fixed.",
+            albums_skipped,
+        )
     for method in ("mbid", "name", "none"):
         row = store.connection.execute(
             "SELECT COUNT(*) AS pairs, COALESCE(SUM(plays), 0) AS plays"

pyproject.toml

@@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta"
 
 [project]
 name = "music-curator"
-version = "0.2.1"
+version = "0.2.3"
 description = "Ingest a Last.fm listening history and curate a music library from it"
 readme = "README.md"
 requires-python = ">=3.11"

tests/conftest.py

@@ -1,7 +1,9 @@
+import http.server
 import io
 import json
 import os
 import sys
+import threading
 import urllib.error
 import urllib.parse
 
@@ -201,6 +203,19 @@ class FakeLidarr:
                 url, 500, "Internal Server Error", {}, io.BytesIO(b'{"message": "boom"}')
             )
 
+        album_ids = query.get("albumIds")
+        if path == "album" and album_ids:
+            album_id = int(album_ids)
+            if ("albumid", album_id) in self.fail:
+                raise urllib.error.HTTPError(
+                    url,
+                    500,
+                    "Internal Server Error",
+                    {},
+                    io.BytesIO(b'{"message": "Sequence contains more than one element"}'),
+                )
+            return json.dumps([row for row in self.albums if row["id"] == album_id])
+
         if path == "artist":
             return json.dumps(self.artists)
         source = {"album": self.albums, "track": self.tracks, "trackfile": self.files}[path]
@@ -228,3 +243,53 @@ def now_playing():
         "mbid": "",
         "@attr": {"nowplaying": "true"},
     }
+
+
+class _CountingServer(http.server.ThreadingHTTPServer):
+    """Counts accepted connections, which is what connection reuse is about."""
+
+    daemon_threads = True
+
+    def __init__(self, *args, **kwargs):
+        self.connections = 0
+        super().__init__(*args, **kwargs)
+
+    def process_request(self, request, client_address):
+        self.connections += 1
+        super().process_request(request, client_address)
+
+
+class _Handler(http.server.BaseHTTPRequestHandler):
+    # Without HTTP/1.1 the server closes after every response and no client
+    # could reuse anything, which would make the test prove nothing.
+    protocol_version = "HTTP/1.1"
+
+    def do_GET(self):
+        if self.path.startswith("/boom"):
+            body, status = b'{"message": "boom"}', 500
+        else:
+            body = json.dumps(
+                {"path": self.path, "key": self.headers.get("X-Api-Key")}
+            ).encode()
+            status = 200
+        self.send_response(status)
+        self.send_header("Content-Type", "application/json")
+        self.send_header("Content-Length", str(len(body)))
+        self.end_headers()
+        self.wfile.write(body)
+
+    def log_message(self, *args):
+        pass
+
+
+@pytest.fixture
+def http_server():
+    """A real local HTTP server, for the one component that talks sockets."""
+    server = _CountingServer(("127.0.0.1", 0), _Handler)
+    thread = threading.Thread(target=server.serve_forever, daemon=True)
+    thread.start()
+    try:
+        yield server, f"http://127.0.0.1:{server.server_port}"
+    finally:
+        server.shutdown()
+        server.server_close()

tests/test_music_curator.py

@@ -1,3 +1,4 @@
+import json
 import urllib.error
 
 import pytest
@@ -503,8 +504,7 @@ def test_matching_is_redone_when_new_scrobbles_arrive(tmp_path):
 
 
 def test_albums_come_from_the_unfiltered_endpoint(tmp_path):
-    """`?artistId=` is Lidarr's unguarded path and 500s on data it cannot
+    """One request, and the only path that skips albums it cannot hydrate."""
-    hydrate; the unfiltered one skips such albums instead."""
     api = FakeLidarr(LIBRARY)
     store = store_at(tmp_path)
 
@@ -515,6 +515,33 @@ def test_albums_come_from_the_unfiltered_endpoint(tmp_path):
     assert store.scalar("SELECT COUNT(*) FROM lidarr_album") == 3
 
 
+def test_a_bad_album_falls_back_to_asking_per_artist(tmp_path):
+    """An album with two monitored releases throws in the resource mapper, so
+    the bulk call dies wholesale. Per artist, only its owner is lost."""
+    # The bulk call fails because artist 2 owns the offending album.
+    api = FakeLidarr(LIBRARY, fail=[("album", 0), ("album", 2)])
+    store = store_at(tmp_path)
+
+    music_curator.index_library(music_curator.Lidarr("http://lidarr", "key", transport=api), store)
+
+    assert store.scalar("SELECT COUNT(*) FROM lidarr_album WHERE artist_id = 2") == 0
+    # The other two artists keep their albums.
+    assert store.scalar("SELECT COUNT(*) FROM lidarr_album") == 2
+    assert store.get_state("index_albums_skipped") == "1"
+
+
+def test_a_bad_album_does_not_cost_that_artist_their_tracks(tmp_path):
+    """Tracks come from a different endpoint with a different mapper, so
+    matching survives an album Lidarr cannot serialise."""
+    api = FakeLidarr(LIBRARY, fail=[("album", 0), ("album", 2)])
+    store = store_at(tmp_path)
+
+    music_curator.index_library(music_curator.Lidarr("http://lidarr", "key", transport=api), store)
+
+    assert store.scalar("SELECT COUNT(*) FROM lidarr_track WHERE artist_id = 2") == 1
+    assert store.get_state("index_skipped") == "0"
+
+
 def test_an_artist_lidarr_cannot_serve_does_not_kill_the_index(tmp_path):
     # Artist 2 is AC/DC in LIBRARY; its track lookup fails.
     api = FakeLidarr(LIBRARY, fail=[("track", 2)])
@@ -558,3 +585,105 @@ def test_a_lidarr_error_carries_the_url_and_what_the_server_said():
     assert "http://lidarr:8686/api/v1/album" in message
     assert "HTTP 500" in message
     assert "boom" in message
+
+
+def test_the_offending_album_is_named_not_just_its_artist(tmp_path, caplog):
+    """An artist's whole discography is too much to click through by hand."""
+    # AC/DC is artist 2; its only album is id 201, holding "Hells Bells".
+    api = FakeLidarr(LIBRARY, fail=[("album", 0), ("album", 2), ("albumid", 201)])
+    store = store_at(tmp_path)
+
+    with caplog.at_level("WARNING"):
+        music_curator.index_library(
+            music_curator.Lidarr("http://lidarr", "key", transport=api), store
+        )
+
+    assert "album id 201" in caplog.text
+    assert "Hells Bells" in caplog.text
+
+
+def test_a_transient_failure_is_not_probed_album_by_album(tmp_path, caplog):
+    """When the resolver is the problem every artist fails, and probing each of
+    them multiplies the load that caused it."""
+
+    def unresolvable(url, timeout=None, headers=None):
+        if "artistId" in url:
+            raise urllib.error.URLError("[Errno -3] Try again")
+        return json.dumps(FakeLidarr(LIBRARY).artists) if url.endswith("artist") else "[]"
+
+    store = store_at(tmp_path)
+    client = music_curator.Lidarr("http://lidarr", "key", transport=unresolvable, backoff=0)
+
+    with caplog.at_level("WARNING"):
+        music_curator.index_library(client, store)
+
+    assert "Try again" in caplog.text
+    assert "cannot serialise" not in caplog.text
+
+
+def test_a_transient_failure_is_retried():
+    attempts = []
+
+    def flaky(url, timeout=None, headers=None):
+        attempts.append(url)
+        if len(attempts) < 3:
+            raise urllib.error.URLError("[Errno -3] Try again")
+        return "[]"
+
+    client = music_curator.Lidarr("http://lidarr", "key", transport=flaky, backoff=0)
+
+    assert client.get("artist") == []
+    assert len(attempts) == 3
+
+
+def test_a_lidarr_500_is_not_retried():
+    """It is an exception inside Lidarr's serialisation, not a busy server."""
+    api = FakeLidarr(LIBRARY, fail=[("album", 0)])
+    client = music_curator.Lidarr("http://lidarr", "key", transport=api, backoff=0)
+
+    with pytest.raises(music_curator.LidarrError) as raised:
+        client.get("album")
+
+    assert raised.value.transient is False
+    assert len(api.calls) == 1
+
+
+def test_keep_alive_uses_one_connection_for_many_requests(http_server):
+    """The point of the whole class: one DNS lookup and one socket, not N."""
+    server, base = http_server
+    transport = music_curator.KeepAlive()
+
+    try:
+        for index in range(5):
+            body = transport(f"{base}/api/v1/artist?n={index}", headers={"X-Api-Key": "key"})
+            assert json.loads(body)["key"] == "key"
+    finally:
+        transport.close()
+
+    assert server.connections == 1
+
+
+def test_keep_alive_maps_an_error_status_onto_httperror(http_server):
+    _, base = http_server
+    transport = music_curator.KeepAlive()
+
+    try:
+        with pytest.raises(urllib.error.HTTPError) as raised:
+            transport(f"{base}/boom", headers={"X-Api-Key": "key"})
+        assert raised.value.code == 500
+        assert music_curator.error_detail(raised.value) == "boom"
+    finally:
+        transport.close()
+
+
+def test_lidarr_talks_to_a_real_server_through_keep_alive(http_server):
+    server, base = http_server
+    client = music_curator.Lidarr(base, "secret")
+
+    try:
+        assert client.get("artist", {"x": 1})["key"] == "secret"
+        assert client.get("album")["path"] == "/api/v1/album"
+    finally:
+        client.transport.close()
+
+    assert server.connections == 1