diff --git a/app/models/mtg/scryfall/source.rb b/app/models/mtg/scryfall/source.rb index af439441..e462abde 100644 --- a/app/models/mtg/scryfall/source.rb +++ b/app/models/mtg/scryfall/source.rb @@ -138,7 +138,11 @@ def prune(dir) dir.glob("*.jsonl.gz").sort_by(&:mtime).reverse.drop(KEEP_DOWNLOADS).each(&:delete) end + # The first check, before any strip or parse: `String#strip` raises Encoding::CompatibilityError on a line that isn't + # valid UTF-8 (ArgumentError when the bad byte comes first), and nothing rescued the first, so one bad byte would stop + # every refresh instead of counting one malformed line (issue #411). MTG::Scryfall::PriceQuotes makes the same check for the same file. def entry_or_malformed(line, allowed) + return Catalog::Sources::Malformed.new(external_key: nil, error: "the line is not valid UTF-8") unless line.valid_encoding? return if line.strip.empty? card = JSON.parse(line) diff --git a/docs/architecture/catalog-operations.md b/docs/architecture/catalog-operations.md index 979bfefa..6cdb2a21 100644 --- a/docs/architecture/catalog-operations.md +++ b/docs/architecture/catalog-operations.md @@ -69,7 +69,7 @@ Statuses: `running`, `applied`, `skipped`, `failed`. Each attempt, a job system 3. Otherwise, if a waiting retry of the type's refresh exists (`Catalog::Operation::Queue#waiting_to_retry?`, leaving out the starting job's own id), record the new run as `skipped` with `waiting for another job's retry` (`Catalog::RefreshRun::WAITING_FOR_RETRY`): it asks the source nothing and runs no `after_refresh` hook, and the waiting job does the work. Manual and scheduled refreshes are treated alike (spec 024 decisions 1, 2, 4, 5, FR-2; spec 002 FR-4; #78). 4. Otherwise the run proceeds. - **Running:** enters the download stage, reads the language setting and asks the source for its current version. A scheduled run whose version was already applied with the same sorted language set ends `skipped` with ` already applied` (rebuilding the name index first if it is empty), and still runs the source's `after_refresh` hook; a manual run applies again, and so does any run whose source's `#reapply?` says so (spec 002 FR-4; spec 011 AC-2.3, AC-3.1). `MTG::Scryfall::Source#reapply?` says so for two reasons: spec 011 AC-2.3's, printings with no artwork id, and spec 058 decision 3's, cards in the catalog and none with a mana value, so an upgraded instance fills the new column on its next refresh even when Scryfall's file is unchanged; the test is that none has one, not that any lacks one, as for artwork ids. Otherwise it downloads, syncs sets and entries, retires unseen entries and rebuilds the name index, in that order. It records each stage at once on entering it, and within a stage its done and total (when the source reports them) and its running counts as soon as `EVERY_RECORDS` records were seen or `EVERY_SECONDS` passed, and at most once per `AT_MOST_EVERY_SECONDS`; each write is also the heartbeat (`Catalog::Refresh::Progress`; spec 015 FR-1, AC-2.9, which allowed up to 5 seconds). A source that can't report how far through it is is still tracked by stage and counts (spec 015 FR-2, AC-2.8). A malformed record is counted as malformed and logged by its key, and a known entry whose record is malformed is kept, not retired; an entry whose set the source's set list lacks gets a set made from the entry's own set code and name (spec 002 FR-3). -- **Ends:** `applied` with its counts (seen, inserted, updated, retired, restored, malformed), then the source's `after_refresh` hook; `failed` with `": "`, the counts so far and the stage it reached, and the error re-raised for the job's retry rules; or `skipped` as above. Every finished run writes one structured log entry, `catalog.refresh.finished` (spec 002 FR-4, FR-5; spec 015 FR-1). A file with no valid records fails the run in the sync stage with `no valid records ( malformed)`, so it never reads as "everything was removed" (spec 015 Error Scenarios). A failed run retires nothing, and the next refresh leaves the catalog as one successful run would (spec 002 FR-4, Reliability; spec 015 AC-3.8). +- **Ends:** `applied` with its counts (seen, inserted, updated, retired, restored, malformed), then the source's `after_refresh` hook; `failed` with `": "`, the counts so far and the stage it reached, and the error re-raised for the job's retry rules; or `skipped` as above. Every finished run writes one structured log entry, `catalog.refresh.finished` (spec 002 FR-4, FR-5; spec 015 FR-1). A file with no valid records fails the run in the sync stage with `no valid records ( malformed)`, so it never reads as "everything was removed" (spec 015 Error Scenarios). A line of the file that isn't valid UTF-8 is one malformed line like any other the source can't read, and the run goes on; `MTG::Scryfall::Source` checks it before it strips or parses the line, because `String#strip` raises on it (#411). A failed run retires nothing, and the next refresh leaves the catalog as one successful run would (spec 002 FR-4, Reliability; spec 015 AC-3.8). What the panel shows (`Catalog::RefreshOperation`; spec 015 Stories 1–3): @@ -216,7 +216,7 @@ Filter chips Failed (the default), Running, Queued and Scheduled, each with its - [Spec 055](../specs/055-rate-limit-retry-now/spec.md): all. - [Spec 058](../specs/058-mtg-mana-value/spec.md) decision 3 (`#reapply?`'s second reason). - ADRs [0014](../adr/0014-hand-built-admin-jobs-console.md), [0015](../adr/0015-admin-progress-by-polling.md), [0018](../adr/0018-collectible-agnostic-catalog-core.md). -- Issues [#60](https://github.com/plainprogrammer/Collector/issues/60), [#61](https://github.com/plainprogrammer/Collector/issues/61), [#73](https://github.com/plainprogrammer/Collector/issues/73), [#74](https://github.com/plainprogrammer/Collector/issues/74), [#78](https://github.com/plainprogrammer/Collector/issues/78), [#79](https://github.com/plainprogrammer/Collector/issues/79), [#80](https://github.com/plainprogrammer/Collector/issues/80), [#81](https://github.com/plainprogrammer/Collector/issues/81), [#84](https://github.com/plainprogrammer/Collector/issues/84), [#86](https://github.com/plainprogrammer/Collector/issues/86), [#111](https://github.com/plainprogrammer/Collector/issues/111), [#122](https://github.com/plainprogrammer/Collector/issues/122), [#176](https://github.com/plainprogrammer/Collector/issues/176), [#77](https://github.com/plainprogrammer/Collector/issues/77) (discarding a waiting retry stays out of scope); open: [#41](https://github.com/plainprogrammer/Collector/issues/41), [#283](https://github.com/plainprogrammer/Collector/issues/283). +- Issues [#60](https://github.com/plainprogrammer/Collector/issues/60), [#61](https://github.com/plainprogrammer/Collector/issues/61), [#73](https://github.com/plainprogrammer/Collector/issues/73), [#74](https://github.com/plainprogrammer/Collector/issues/74), [#78](https://github.com/plainprogrammer/Collector/issues/78), [#79](https://github.com/plainprogrammer/Collector/issues/79), [#80](https://github.com/plainprogrammer/Collector/issues/80), [#81](https://github.com/plainprogrammer/Collector/issues/81), [#84](https://github.com/plainprogrammer/Collector/issues/84), [#86](https://github.com/plainprogrammer/Collector/issues/86), [#111](https://github.com/plainprogrammer/Collector/issues/111), [#122](https://github.com/plainprogrammer/Collector/issues/122), [#176](https://github.com/plainprogrammer/Collector/issues/176), [#77](https://github.com/plainprogrammer/Collector/issues/77) (discarding a waiting retry stays out of scope), [#411](https://github.com/plainprogrammer/Collector/issues/411); open: [#41](https://github.com/plainprogrammer/Collector/issues/41), [#283](https://github.com/plainprogrammer/Collector/issues/283). ## Distillation log @@ -229,3 +229,4 @@ Filter chips Failed (the default), Running, Queued and Scheduled, each with its | 2026-11-09 | Spec 053 (the art index's "Out of date" state for a build made with other settings and its status line, the "Warning" fact and line suffix for a build made for an older catalog, what the scanner does with each kind of drift, the accepted limits) and issue #176 | [#241](https://github.com/plainprogrammer/Collector/pull/241) | | 2026-11-09 | Spec 055 (Retry now for a failed run's own job waiting to retry: what it moves and how, one winner, the offer in one place, the refresh's "Queued to retry" tied to its own job, wording, admin only) and issue #77 | [#244](https://github.com/plainprogrammer/Collector/pull/244) | | 2026-11-10 | Spec 058 (decision 3: `#reapply?`'s second reason, an upgraded instance filling the new column on its next refresh; the partial-failure and no-`cmc` limits) and issue #250 | [#279](https://github.com/plainprogrammer/Collector/pull/279) | +| 2026-11-13 | Issue #411 (a bulk-file line that isn't valid UTF-8 counts as one malformed line and the refresh goes on); no spec | #411's pull request | diff --git a/spec/models/mtg/scryfall/source_spec.rb b/spec/models/mtg/scryfall/source_spec.rb index 77a6201c..3a7f0cb6 100644 --- a/spec/models/mtg/scryfall/source_spec.rb +++ b/spec/models/mtg/scryfall/source_spec.rb @@ -143,6 +143,23 @@ expect(yielded.grep(Catalog::Sources::EntryRecord).map(&:external_key)).to eq(%w[en-1 ja-1]) expect(yielded.grep(Catalog::Sources::Malformed).map(&:external_key)).to eq([ "bad-1", nil ]) end + + # Issue #411: String#strip raises Encoding::CompatibilityError on such a line, which no rescue caught, so one bad byte + # stopped the whole refresh instead of counting one malformed line. + it "yields a Malformed for a line that is not valid UTF-8, and goes on with the next line (#411)", :aggregate_failures do + path = dir.join("f.jsonl.gz") + Zlib::GzipWriter.open(path.to_s) do |gzip| + gzip.write("{\"id\":\"bad\",\"name\":\"\xFF\"}\n".b) + gzip.write("#{JSON.generate(scryfall_card("id" => "good"))}\n".b) + end + + yielded = [] + source.each_entry(path, languages: %w[en]) { |record| yielded << record } + + expect(yielded.map(&:class)).to eq([ Catalog::Sources::Malformed, Catalog::Sources::EntryRecord ]) + expect([ yielded.first.external_key, yielded.first.error ]).to eq([ nil, "the line is not valid UTF-8" ]) + expect(yielded.last.external_key).to eq("good") + end end describe "progress (spec 015 FR-2)" do