Skip to content

Commit cf1bf00

Browse files
Disable cluster-dedup pre-pass: net wall-clock loss at full-catalog scale
Its own sequential ~21.6h cost (unaffected by --workers) exceeded the compute time it saved by absorbing ~20-28% of cards - HOLD #2's own numbers showed 1.82 days raw vs 2.34 days with clustering. Also zero progress visibility for its entire duration, indistinguishable from a hung process. compute_own_image_clusters/ClusterResult left intact for a future chunk-scoped redesign; run_pilot now passes a no-op ClusterResult instead of calling it. 4 integration tests marked skip with a clear reason, not deleted. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016i9S7LQsCL3FGaih3ZTRBJ
1 parent a741ab7 commit cf1bf00

3 files changed

Lines changed: 58 additions & 6 deletions

File tree

MPCAutofill/cardpicker/local_identify_printing_tags.py

Lines changed: 20 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -722,11 +722,26 @@ def run_pilot(
722722
printing_pks_in_scope.update(c.pk for c in s.candidates)
723723
uncovered_printing_pks_in_scope = printing_pks_in_scope - covered_printing_pks_before
724724

725-
# addendum item 2a (2026-07-15): collapse distance-0 duplicate-image clusters to one
726-
# representative BEFORE slicing/chunking - only representatives reach _compute_card; an
727-
# absorbed member's vote comes from propagation in the write loop below instead.
728-
cluster_result = compute_own_image_clusters(list(all_selected_by_card_id.values()), fetch_dpi)
729-
all_selected_by_card_id = {s.card.pk: s for s in cluster_result.representatives}
725+
# addendum item 2a (2026-07-15) - DISABLED (2026-07-16, live full-catalog run): the
726+
# pre-pass itself is a genuine wall-clock net LOSS at full-catalog scale, not just an
727+
# optimization with a cost - it's a fully SEQUENTIAL fetch over the entire selected pool
728+
# (~172k cards), unaffected by --workers (see task #108's original finding), costing
729+
# ~21.6h fixed regardless of core count - MORE than the compute time it saves by
730+
# absorbing ~20-28% of cards into cheap propagated votes. Confirmed directly against this
731+
# session's own HOLD #2 numbers: raw/no-clustering projected 1.82 days vs.
732+
# cluster-dedup-adjusted 2.34 days - the "optimization" made the real run slower. It also
733+
# has zero progress visibility for its entire duration (no print statements inside
734+
# compute_own_image_clusters), which looks identical to a hung process from the outside -
735+
# a job silently in this phase for 31 minutes was mistaken for possibly stuck before this
736+
# was diagnosed. Left in place, not called: `compute_own_image_clusters`, `ClusterResult`,
737+
# and all of the propagation/absorption logic below still work correctly against a
738+
# no-op ClusterResult (every selected card is its own "representative", zero clusters) -
739+
# this is the minimal, structurally-safe way to disable the feature without touching the
740+
# write-loop code that depends on `cluster_result`'s shape. A future chunk-scoped redesign
741+
# (compute the hash from the SAME image _compute_card already fetches for OCR/phash,
742+
# cluster within a chunk instead of the whole pool) could recover the dedup benefit
743+
# without the sequential-pre-pass cost or the observability gap - not built here.
744+
cluster_result = ClusterResult(representatives=list(all_selected_by_card_id.values()), members_by_representative={})
730745
attributes.cluster_count = len(cluster_result.members_by_representative)
731746
attributes.cards_absorbed_into_clusters = sum(len(m) for m in cluster_result.members_by_representative.values())
732747

MPCAutofill/cardpicker/tests/test_local_identify_printing_tags.py

Lines changed: 24 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1390,9 +1390,24 @@ def test_workers_one_does_not_set_omp_thread_limit(self, db, monkeypatch):
13901390
assert "OMP_THREAD_LIMIT" not in os.environ
13911391

13921392

1393+
_CLUSTERING_DISABLED_REASON = (
1394+
"addendum item 2a's clustering pre-pass is disabled in run_pilot (2026-07-16) - it's a "
1395+
"sequential fetch over the whole selected pool, unaffected by --workers, and its own fixed "
1396+
"cost measurably exceeded the compute time it saved at full-catalog scale (see "
1397+
"local_identify_printing_tags.py's run_pilot comment at the cluster_result assignment). "
1398+
"compute_own_image_clusters itself is untouched and still tested directly above; only the "
1399+
"run_pilot integration is skipped until a future chunk-scoped redesign re-enables it."
1400+
)
1401+
1402+
13931403
class TestClusterDedup:
13941404
"""Addendum item 2a (2026-07-15): distance-0 (byte-identical fetched image) clustering,
1395-
scoped to this run only - no schema/content_hash persistence (that's item 2b, deferred)."""
1405+
scoped to this run only - no schema/content_hash persistence (that's item 2b, deferred).
1406+
1407+
NOTE (2026-07-16): run_pilot no longer calls compute_own_image_clusters (see
1408+
_CLUSTERING_DISABLED_REASON) - the tests below that exercise clustering directly still
1409+
pass and still matter; the ones that expect run_pilot's own integration to cluster are
1410+
marked skip, not deleted, so they're ready to re-enable alongside a future redesign."""
13961411

13971412
def test_two_cards_with_identical_images_cluster_with_lower_pk_as_representative(self, db):
13981413
CanonicalCardFactory(name="Forest")
@@ -1458,6 +1473,7 @@ def test_unfetchable_image_stays_a_singleton_representative(self, db, monkeypatc
14581473
assert cluster_result.members_by_representative == {}
14591474
assert [s.card.pk for s in cluster_result.representatives] == [card.pk]
14601475

1476+
@pytest.mark.skip(reason=_CLUSTERING_DISABLED_REASON)
14611477
def test_accepted_vote_on_representative_propagates_to_absorbed_member(self, db, monkeypatch):
14621478
printing = CanonicalCardFactory(name="Forest", expansion=CanonicalExpansionFactory(code="aaa"))
14631479
card_a = CardFactory(name="Forest")
@@ -1491,6 +1507,11 @@ def test_accepted_vote_on_representative_propagates_to_absorbed_member(self, db,
14911507
assert vote_a.source == vote_b.source == VoteSource.OCR
14921508
assert vote_a.is_no_match == vote_b.is_no_match is False
14931509

1510+
@pytest.mark.skip(
1511+
reason=_CLUSTERING_DISABLED_REASON + " Passes vacuously with clustering off (no "
1512+
"propagation is ever attempted, so the guard it tests is never exercised) - skipped "
1513+
"rather than left green for the wrong reason."
1514+
)
14941515
def test_member_with_an_existing_vote_from_a_prior_run_is_not_double_voted_or_overwritten(self, db, monkeypatch):
14951516
printing = CanonicalCardFactory(name="Forest", expansion=CanonicalExpansionFactory(code="aaa"))
14961517
other_printing = CanonicalCardFactory(name="Forest", expansion=CanonicalExpansionFactory(code="bbb"))
@@ -1533,6 +1554,7 @@ def test_member_with_an_existing_vote_from_a_prior_run_is_not_double_voted_or_ov
15331554
assert untouched_vote.pk == existing_vote.pk
15341555
assert untouched_vote.printing_id == other_printing.pk # unchanged, not overwritten
15351556

1557+
@pytest.mark.skip(reason=_CLUSTERING_DISABLED_REASON)
15361558
def test_absorbed_member_never_reaches_ocr_or_phash_processing(self, db, monkeypatch):
15371559
# the whole point of dedup is not re-running the expensive engines on cluster members -
15381560
# this is the test that actually proves the efficiency win, not just vote correctness.
@@ -1559,6 +1581,7 @@ def recording_run_ocr_for_card(selected, image, crop_box, bleed_class=None):
15591581
assert ocr_called_for_card_ids == [card_a.pk]
15601582
assert card_b.pk not in ocr_called_for_card_ids
15611583

1584+
@pytest.mark.skip(reason=_CLUSTERING_DISABLED_REASON)
15621585
def test_absorbed_members_own_engine_eligibility_still_runs_via_the_representative(self, db, monkeypatch):
15631586
# card_a (the lower-pk representative) is only phash-eligible; card_b (absorbed member)
15641587
# is only ocr-eligible - the representative must still run OCR on card_a's behalf, or

docs/lessons.md

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -332,3 +332,17 @@ scan time (`transform_image_into_object`/`unpack_name` extract name/tags/languag
332332
it requires either a one-time raw-filename capture added to the import path going forward
333333
(useless retroactively for already-imported cards) or re-deriving candidate filenames from the
334334
Drive API directly per source (expensive, not a DB query).
335+
336+
## A sequential single-item pre-pass over a large pool needs its own progress logging, not just the loop after it
337+
338+
`local_identify_printing_tags.py`'s cluster-dedup pre-pass (`compute_own_image_clusters`)
339+
fetches every selected candidate's image ONE AT A TIME before the main chunked loop - which
340+
does have `progress_every` logging - even starts. A full-catalog run sat silent for 31 minutes
341+
before anyone could tell whether it was working or hung, because the pre-pass itself prints
342+
nothing for its entire (potentially many-hour) duration. Same shape as "verify claims before
343+
trusting aggregate numbers" (see this doc's other entries), applied to job observability
344+
specifically: a genuinely-working process with zero output is indistinguishable from a dead one
345+
from the outside, and "give it more time" is not a diagnosis. Any future sequential phase over a
346+
large pool - a pre-pass, a warm-up cache fill, a one-time backfill scan - needs a periodic print
347+
(even a bare `print(f"... {i}/{n}")` every few hundred items) BEFORE it ships for an unattended
348+
run, not added after the first time someone has to guess whether it's stuck.

0 commit comments

Comments
 (0)