← back to Dw Kravet Hires
TK-12090 Fix 2: apply-hires.mjs — orphan-media ledgering + throttle backoff
1a1afae739708d282c88f298531e1171eac62e19 · 2026-09-24 08:06:08 -0700 · Steve Abrams
2a — a throw AFTER productCreateMedia succeeded (poll/reorder/ledger-write)
left the new media live on the product with no ledger row, so --rollback
(ledger-driven) was blind to it. newMediaId is now tracked outside the
try block; the catch path writes an `orphaned: true` row (old_media_id,
orphaned_media_id, the error) to both the per-run ledger and the fleet
exec-ledger instead of attempting a best-effort delete that could itself
throw on the same fault that caused the orphan. --rollback now splits
completed swaps (reorder back to old_media_id) from orphan rows (delete
the orphan media outright, since nothing was ever displaced) so an
orphan is never mistaken for an applied swap.
2b — shopify() threw immediately on THROTTLED/429 with no retry, and this
script shares one SHOPIFY_ADMIN_TOKEN rate bucket with T4
(shopify-room-mockup.py). Added bounded exponential backoff + jitter
(--max-retries, default 6), honoring Shopify's own throttleStatus hint
or a Retry-After header when present, with every backoff logged so a
throttled run is visibly slow rather than silently stalled. Concurrency
is unchanged (batches stay sequential).
Negative tests (scripted global.fetch mock, zero live Shopify calls):
post-create throw -> orphan row + rollback dry-run/live correctly
delete-not-reorder it; THROTTLED -> retry+recover with an honored wait;
always-THROTTLED -> bounded retries (exhausts, reports failed, never
hangs or falsely applies). All 6 checks pass; real fleet ledgers
(project apply-ledger.jsonl + ~/.claude/.../executed-reversible/ledger.jsonl)
confirmed untouched by the test run.
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KXUyzc9vybUz39rhnNJdwY
Files touched
M scripts/apply-hires.mjs
Diff
commit 1a1afae739708d282c88f298531e1171eac62e19
Author: Steve Abrams <steve@designerwallcoverings.com>
Date: Thu Sep 24 08:06:08 2026 -0700
TK-12090 Fix 2: apply-hires.mjs — orphan-media ledgering + throttle backoff
2a — a throw AFTER productCreateMedia succeeded (poll/reorder/ledger-write)
left the new media live on the product with no ledger row, so --rollback
(ledger-driven) was blind to it. newMediaId is now tracked outside the
try block; the catch path writes an `orphaned: true` row (old_media_id,
orphaned_media_id, the error) to both the per-run ledger and the fleet
exec-ledger instead of attempting a best-effort delete that could itself
throw on the same fault that caused the orphan. --rollback now splits
completed swaps (reorder back to old_media_id) from orphan rows (delete
the orphan media outright, since nothing was ever displaced) so an
orphan is never mistaken for an applied swap.
2b — shopify() threw immediately on THROTTLED/429 with no retry, and this
script shares one SHOPIFY_ADMIN_TOKEN rate bucket with T4
(shopify-room-mockup.py). Added bounded exponential backoff + jitter
(--max-retries, default 6), honoring Shopify's own throttleStatus hint
or a Retry-After header when present, with every backoff logged so a
throttled run is visibly slow rather than silently stalled. Concurrency
is unchanged (batches stay sequential).
Negative tests (scripted global.fetch mock, zero live Shopify calls):
post-create throw -> orphan row + rollback dry-run/live correctly
delete-not-reorder it; THROTTLED -> retry+recover with an honored wait;
always-THROTTLED -> bounded retries (exhausts, reports failed, never
hangs or falsely applies). All 6 checks pass; real fleet ledgers
(project apply-ledger.jsonl + ~/.claude/.../executed-reversible/ledger.jsonl)
confirmed untouched by the test run.
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KXUyzc9vybUz39rhnNJdwY
---
scripts/apply-hires.mjs | 118 ++++++++++++++++++++++++++++++++++++++++++------
1 file changed, 105 insertions(+), 13 deletions(-)
diff --git a/scripts/apply-hires.mjs b/scripts/apply-hires.mjs
index 17d2673..3c65f16 100644
--- a/scripts/apply-hires.mjs
+++ b/scripts/apply-hires.mjs
@@ -79,20 +79,58 @@ function shopTok() {
return tok.trim();
}
-async function shopify(query, variables) {
+const sleep = (ms) => new Promise((res) => setTimeout(res, ms));
+
+// TK-12090 2b — T3 (this script) and T4 (shopify-room-mockup.py) share one
+// SHOPIFY_ADMIN_TOKEN rate bucket, and this script previously threw hard on
+// THROTTLED/429 with no retry, so a busy shared bucket silently killed a run.
+// Bounded exponential backoff + jitter, honoring Shopify's own throttleStatus
+// hint (extensions.cost.throttleStatus) or a Retry-After header when present.
+// Concurrency is never raised — batches stay sequential; only the per-call
+// wait grows.
+const MAX_RETRIES = parseInt(val('--max-retries', '6'), 10);
+
+async function backoffRetry(reason, query, variables, attempt, retryAfterHeader, throttleStatus) {
+ if (attempt >= MAX_RETRIES) {
+ throw new Error(`shopify gql: ${reason} — exhausted ${MAX_RETRIES} retries`);
+ }
+ let waitMs = 0;
+ if (throttleStatus && throttleStatus.currentlyAvailable != null && throttleStatus.restoreRate) {
+ // rough single-query cost guess (Shopify's typical simple-query cost ~50pts)
+ const need = Math.max(0, 50 - throttleStatus.currentlyAvailable);
+ waitMs = Math.ceil((need / throttleStatus.restoreRate) * 1000);
+ } else if (retryAfterHeader) {
+ waitMs = parseFloat(retryAfterHeader) * 1000 || 0;
+ }
+ const base = Math.min(30000, 1000 * Math.pow(2, attempt)); // 1s,2s,4s,8s,16s,30s(cap)
+ waitMs = Math.max(waitMs, base) + Math.floor(Math.random() * 500); // + jitter
+ console.log(` … ${reason}, backing off ${Math.round(waitMs)}ms (retry ${attempt + 1}/${MAX_RETRIES})`);
+ await sleep(waitMs);
+ return shopify(query, variables, attempt + 1);
+}
+
+async function shopify(query, variables, attempt = 0) {
const r = await fetch(`https://${SHOP}.myshopify.com/admin/api/${API}/graphql.json`, {
method: 'POST',
headers: { 'X-Shopify-Access-Token': shopTok(), 'Content-Type': 'application/json' },
body: JSON.stringify({ query, variables }),
signal: AbortSignal.timeout(60000),
});
+ if (r.status === 429) {
+ return backoffRetry('HTTP 429', query, variables, attempt, r.headers.get('retry-after'), null);
+ }
const j = await r.json();
- if (j.errors) throw new Error('shopify gql: ' + JSON.stringify(j.errors));
+ if (j.errors) {
+ const throttled = Array.isArray(j.errors) &&
+ j.errors.some((e) => e?.extensions?.code === 'THROTTLED' || /throttl/i.test(e?.message || ''));
+ if (throttled) {
+ return backoffRetry('THROTTLED', query, variables, attempt, null, j.extensions?.cost?.throttleStatus);
+ }
+ throw new Error('shopify gql: ' + JSON.stringify(j.errors));
+ }
return j.data;
}
-const sleep = (ms) => new Promise((res) => setTimeout(res, ms));
-
// Read the LIVE featured (position-0) image media: {id, url, width}. Null if no image media.
async function liveFeatured(gid) {
const d = await shopify(
@@ -162,6 +200,13 @@ async function applyLive(rows) {
for (const r of batch) {
const gid = String(r.shopify_id).startsWith('gid://') ? r.shopify_id : `gid://shopify/Product/${r.shopify_id}`;
const anchorUrl = (r.rollback_url || r.current_400px_url).split('?')[0];
+ // TK-12090 2a — tracked OUTSIDE the try so the catch block can see whether
+ // productCreateMedia already succeeded this iteration before a LATER step
+ // (poll/reorder/ledger) throws. Without this, a post-create throw left an
+ // orphaned media on the product with no ledger row, so --rollback was
+ // blind to it (rollback is ledger-driven; an unledgered media is invisible).
+ let newMediaId = null;
+ let oldMediaId = null;
try {
// 1) read live featured media = old_media_id anchor + idempotency/race check
const lf = await liveFeatured(gid);
@@ -174,16 +219,16 @@ async function applyLive(rows) {
console.log(` ⤫ SKIP (featured already moved: live=${curWidth}px limit=${MAX_WIDTH} ${curUrl === anchorUrl ? 'same-url' : 'diff-url'}) ${r.mfr_sku}`);
continue;
}
- const oldMediaId = lf.first.id;
+ oldMediaId = lf.first.id;
// 2) add the hi-res as new media
const cm = await shopify(
`mutation($pid:ID!,$media:[CreateMediaInput!]!){
productCreateMedia(productId:$pid, media:$media){ media{ id status } mediaUserErrors{ field message } } }`,
{ pid: gid, media: [{ originalSource: r.proposed_hires_url, mediaContentType: 'IMAGE', alt: lf.title }] });
- const newMediaId = cm.productCreateMedia.media?.[0]?.id;
+ newMediaId = cm.productCreateMedia.media?.[0]?.id;
const errs = cm.productCreateMedia.mediaUserErrors || [];
- if (!newMediaId || errs.length) { failed++; console.log(` ✗ ${r.mfr_sku} createMedia err: ${JSON.stringify(errs)}`); continue; }
+ if (!newMediaId || errs.length) { newMediaId = null; failed++; console.log(` ✗ ${r.mfr_sku} createMedia err: ${JSON.stringify(errs)}`); continue; }
// 3) poll processing; self-heal if it never reaches READY
let st = 'PROCESSING', tries = 0;
@@ -196,6 +241,7 @@ async function applyLive(rows) {
await shopify(`mutation($ids:[ID!]!,$pid:ID!){ productDeleteMedia(mediaIds:$ids,productId:$pid){ deletedMediaIds } }`, { ids: [newMediaId], pid: gid });
healed++;
console.log(` ⚠ ${r.mfr_sku} new media ${st} (orig likely >${MAX_HIRES}px) → removed, old 400px kept featured`);
+ newMediaId = null; // cleanly removed — not an orphan, catch below must not re-record it
continue;
}
@@ -214,10 +260,32 @@ async function applyLive(rows) {
undo_cmd: `node scripts/apply-hires.mjs --rollback --ticket ${TICKET} --ledger ${path.relative(PROJ, LEDGER_PATH)} --live`,
verify: `product ${gid} featured media == ${newMediaId} (hi-res); old ${oldMediaId} retained` });
applied++;
+ newMediaId = null; // fully recorded — nothing left for the catch below to worry about
console.log(` ✓ ${r.mfr_sku} featured -> hi-res (old ${oldMediaId} kept)`);
} catch (e) {
failed++;
console.log(` ✗ ${r.mfr_sku} ${String(e).slice(0, 140)}`);
+ if (newMediaId) {
+ // Media WAS created on Shopify this iteration but a later step threw
+ // before it got ledgered. Prefer a ledger row over a best-effort
+ // delete (a delete attempt here can itself throw, e.g. on the exact
+ // network error that caused the original failure) — a row rollback
+ // can act on beats a delete that silently doesn't happen.
+ const orphanRec = { ts: new Date().toISOString(), ticket: TICKET, shopify_id: gid, vendor: r.vendor, mfr_sku: r.mfr_sku,
+ old_media_id: oldMediaId, old_url: anchorUrl, orphaned_media_id: newMediaId, new_url: r.proposed_hires_url,
+ orphaned: true, error: String(e).slice(0, 200) };
+ try {
+ fs.appendFileSync(LEDGER_PATH, JSON.stringify(orphanRec) + '\n');
+ appendExecLedger({ ts: orphanRec.ts, agent: AGENT, ticket: TICKET,
+ action: `ORPHANED media on error ${r.mfr_sku}: created ${newMediaId}, never featured/ledgered (${orphanRec.error})`,
+ blast_radius: 1,
+ undo_cmd: `node scripts/apply-hires.mjs --rollback --ticket ${TICKET} --ledger ${path.relative(PROJ, LEDGER_PATH)} --live`,
+ verify: `product ${gid} media list no longer contains ${newMediaId}` });
+ console.log(` ⚠ ${r.mfr_sku} orphaned media ${newMediaId} recorded for rollback cleanup`);
+ } catch (e2) {
+ console.log(` ✗✗ ${r.mfr_sku} ORPHAN LEDGER WRITE ALSO FAILED — media ${newMediaId} exists on ${gid} with NO recorded undo: ${String(e2).slice(0, 140)}`);
+ }
+ }
}
}
if (b < batches - 1) { console.log(` … pacing ${GAP}s before next batch (customer-facing) …`); await sleep(GAP * 1000); }
@@ -231,21 +299,30 @@ async function applyLive(rows) {
async function rollback() {
if (!fs.existsSync(LEDGER_PATH)) { console.error(`no ledger at ${LEDGER_PATH}`); process.exit(2); }
const all = fs.readFileSync(LEDGER_PATH, 'utf8').trim().split('\n').filter(Boolean).map((l) => JSON.parse(l))
- .filter((r) => r.old_media_id && r.shopify_id);
+ .filter((r) => r.shopify_id);
// SCOPED BY DEFAULT: the shared apply-ledger.jsonl accumulates every ticket's swaps
// (TK-11658 + TK-11740 + TK-11742 + …), so an unscoped rollback over-reverts sibling
// phases. Reverse only THIS ticket's entries unless --all-tickets is explicitly passed.
- const recs = ALL_TICKETS ? all : all.filter((r) => r.ticket === TICKET);
+ const scoped = ALL_TICKETS ? all : all.filter((r) => r.ticket === TICKET);
+ // TK-12090 2a — an ORPHANED row (media created, never featured/ledgered as a
+ // completed swap because a later step threw) is a different action than a
+ // completed swap: there is nothing to re-point (the old media was never
+ // displaced), just extra media to remove. Handle the two classes separately
+ // so an orphan row is never mistaken for "already applied" and reordered.
+ const recs = scoped.filter((r) => !r.orphaned && r.old_media_id && r.new_media_id);
+ const orphans = scoped.filter((r) => r.orphaned && r.orphaned_media_id);
const scope = ALL_TICKETS ? 'ALL tickets' : `--ticket ${TICKET} only`;
console.log(`\n=== ${TICKET} apply-hires — ROLLBACK ${LIVE ? '(LIVE)' : '(dry-run)'} ===`);
- console.log(`ledger: ${LEDGER_PATH} (scope: ${scope} — ${recs.length} of ${all.length} swaps to reverse)`);
- if (!ALL_TICKETS && recs.length === 0) {
+ console.log(`ledger: ${LEDGER_PATH} (scope: ${scope} — ${recs.length} swap(s) to reverse, ${orphans.length} orphaned media to clean up, of ${all.length} total rows)`);
+ if (!ALL_TICKETS && recs.length === 0 && orphans.length === 0) {
console.error(`no ledger entries for ticket ${TICKET}. Pass --ticket <TK-...> or --all-tickets.`); process.exit(2);
}
if (!LIVE) {
recs.slice(0, 15).forEach((r) => console.log(` would re-point ${r.mfr_sku} featured -> old_media_id ${r.old_media_id}`));
if (recs.length > 15) console.log(` … +${recs.length - 15} more …`);
- console.log(`\nadd --live to actually re-point. Nothing fired.`);
+ orphans.slice(0, 15).forEach((r) => console.log(` would DELETE orphaned media ${r.orphaned_media_id} (${r.mfr_sku}, never featured) — ${r.error || ''}`));
+ if (orphans.length > 15) console.log(` … +${orphans.length - 15} more orphans …`);
+ console.log(`\nadd --live to actually re-point/delete. Nothing fired.`);
return;
}
let done = 0, err = 0;
@@ -263,7 +340,22 @@ async function rollback() {
console.log(` ↩ ${r.mfr_sku} featured restored -> ${r.old_media_id}`);
} catch (e) { err++; console.error(` ✗ ${r.mfr_sku} ${String(e).slice(0, 120)}`); }
}
- console.log(`\n=== rollback done: restored=${done} errors=${err} ===`);
+ let orphansCleaned = 0, orphanErr = 0;
+ for (const r of orphans) {
+ const gid = String(r.shopify_id).startsWith('gid://') ? r.shopify_id : `gid://shopify/Product/${r.shopify_id}`;
+ try {
+ await shopify(
+ `mutation($ids:[ID!]!,$pid:ID!){ productDeleteMedia(mediaIds:$ids,productId:$pid){ deletedMediaIds mediaUserErrors{ message } } }`,
+ { ids: [r.orphaned_media_id], pid: gid });
+ appendExecLedger({ ts: new Date().toISOString(), agent: AGENT, ticket: TICKET,
+ action: `ROLLBACK cleaned up orphaned media ${r.mfr_sku}: deleted ${r.orphaned_media_id}`,
+ blast_radius: 1, undo_cmd: 'n/a (media deleted; nothing left to undo)',
+ verify: `product ${gid} media list no longer contains ${r.orphaned_media_id}` });
+ orphansCleaned++;
+ console.log(` 🗑 ${r.mfr_sku} orphaned media ${r.orphaned_media_id} deleted`);
+ } catch (e) { orphanErr++; console.error(` ✗ ${r.mfr_sku} orphan cleanup failed: ${String(e).slice(0, 120)}`); }
+ }
+ console.log(`\n=== rollback done: restored=${done} errors=${err} | orphans cleaned=${orphansCleaned} errors=${orphanErr} ===`);
}
// --------------------------------- main --------------------------------------
← 7280da7 auto-data-snapshot: 2026-09-24T07:06:26 (1 data files) — scr
·
back to Dw Kravet Hires
·
TK-12097: no-source re-scrape lane (763 A/C/D) characterized 011ebf6 →