[object Object]

← back to Dw Signup Fulfillment

TK-11285: close the second-writer race the deploy preflight required

bef6f4faaf78974b73f6038ea1a4455b15d081e4 · 2026-09-10 07:46:56 -0700 · Steve Abrams

The deploy memo made "identify all processes writing trade-applications.jsonl"
a mandatory precondition, because the shipped decision lock only coordinates
inside the service process. That inventory had never been done. It has one hit:

  scripts/recover-stuck-apps.js

It rewrites the whole jsonl from a snapshot taken before a batch of Shopify
calls and George sends, so its read->write window is minutes. It is not
hypothetical - it has run in prod twice (data/recovery-20260903T192941.json,
recovery-20260903T193258.json) and 20 rows currently qualify for --send-only.

Reproduced with both sides running real production code in separate processes
(verification/tk11285/race.js; only lib/email + lib/shopify stubbed, zero
external calls). Deterministic, 3/3:

  - a trade application submitted during the window is silently destroyed
  - a COMPLETED approval reverts to pending after approve() returned
    ok:true/"approved", the applicant was emailed and the customer was already
    tagged trade_approved - store and Shopify silently disagree, which is the
    exact invariant this ticket exists to enforce

Control (same code, no second writer) shows NO LOSS, so the loss is caused by
the second writer, not by the fix.

Fix applies the pattern lib/trade.js already uses in checkpointApproval: never
write a stale snapshot. Re-read at write time and merge only the fields this
script owns. Link fields are dropped for a row the service has since decided;
email receipts are always kept so a later run cannot re-send a duplicate letter.

After: 3/3 NO LOSS, the script still links and still stamps all 6 receipts.
Regression: trade-approval-test.js 27/27 PASS 0 FAIL, DRY_RUN selftest all pass.

Local artifact only - no deploy, no push, no live writes.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NEDp3MXiKVJ5GDKaQCHZon

Files touched

Diff

commit bef6f4faaf78974b73f6038ea1a4455b15d081e4
Author: Steve Abrams <steve@designerwallcoverings.com>
Date:   Thu Sep 10 07:46:56 2026 -0700

    TK-11285: close the second-writer race the deploy preflight required
    
    The deploy memo made "identify all processes writing trade-applications.jsonl"
    a mandatory precondition, because the shipped decision lock only coordinates
    inside the service process. That inventory had never been done. It has one hit:
    
      scripts/recover-stuck-apps.js
    
    It rewrites the whole jsonl from a snapshot taken before a batch of Shopify
    calls and George sends, so its read->write window is minutes. It is not
    hypothetical - it has run in prod twice (data/recovery-20260903T192941.json,
    recovery-20260903T193258.json) and 20 rows currently qualify for --send-only.
    
    Reproduced with both sides running real production code in separate processes
    (verification/tk11285/race.js; only lib/email + lib/shopify stubbed, zero
    external calls). Deterministic, 3/3:
    
      - a trade application submitted during the window is silently destroyed
      - a COMPLETED approval reverts to pending after approve() returned
        ok:true/"approved", the applicant was emailed and the customer was already
        tagged trade_approved - store and Shopify silently disagree, which is the
        exact invariant this ticket exists to enforce
    
    Control (same code, no second writer) shows NO LOSS, so the loss is caused by
    the second writer, not by the fix.
    
    Fix applies the pattern lib/trade.js already uses in checkpointApproval: never
    write a stale snapshot. Re-read at write time and merge only the fields this
    script owns. Link fields are dropped for a row the service has since decided;
    email receipts are always kept so a later run cannot re-send a duplicate letter.
    
    After: 3/3 NO LOSS, the script still links and still stamps all 6 receipts.
    Regression: trade-approval-test.js 27/27 PASS 0 FAIL, DRY_RUN selftest all pass.
    
    Local artifact only - no deploy, no push, no live writes.
    
    Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
    Claude-Session: https://claude.ai/code/session_01NEDp3MXiKVJ5GDKaQCHZon
---
 scripts/recover-stuck-apps.js         | 64 ++++++++++++++++++++++++++++--
 verification/tk11285/control.json     | 12 ++++++
 verification/tk11285/race-after.json  | 12 ++++++
 verification/tk11285/race-before.json | 12 ++++++
 verification/tk11285/race.js          | 74 +++++++++++++++++++++++++++++++++++
 verification/tk11285/race.json        | 12 ++++++
 verification/tk11285/stubs.js         | 38 ++++++++++++++++++
 7 files changed, 221 insertions(+), 3 deletions(-)

diff --git a/scripts/recover-stuck-apps.js b/scripts/recover-stuck-apps.js
index 22e679c..06e185d 100644
--- a/scripts/recover-stuck-apps.js
+++ b/scripts/recover-stuck-apps.js
@@ -53,6 +53,64 @@ const sleep = (ms) => new Promise((r) => setTimeout(r, ms));
 
 function readRows() { return fs.readFileSync(FILE, 'utf8').split('\n').filter(Boolean).map((l) => JSON.parse(l)); }
 function writeRows(rows) { fs.writeFileSync(FILE, rows.map((r) => JSON.stringify(r)).join('\n') + (rows.length ? '\n' : '')); }
+
+// TK-11285 preflight: this script is a SECOND, out-of-process writer of the same
+// jsonl the live service writes. Its read->write window spans every Shopify call and
+// George send in the batch (minutes), and a naive writeRows(snapshot) silently
+// destroys anything the service did meanwhile: a trade application submitted during
+// the window vanishes, and a COMPLETED approval reverts to pending even though the
+// customer was already tagged trade_approved and emailed. lib/trade.js's decision
+// lock cannot see us - it only coordinates inside the service process.
+//
+// So never write a stale snapshot. Re-read at write time and merge ONLY the fields
+// this script owns onto the fresh rows (same shape as trade.checkpointApproval).
+// Rows we never touched are preserved verbatim; rows the service has since decided
+// are left alone and reported.
+// LINK_FIELDS describe work we did against Shopify for a row we believed was still
+// pending; if the service has since decided that row, they are dropped.
+// RECEIPT_FIELDS only record mail WE already sent - they never conflict with a
+// decision, and dropping them would make a later run re-send a duplicate letter.
+const LINK_FIELDS = ['shopify_customer_id', 'link_status', 'link_via', 'link_created',
+  'link_error', 'recovered_at'];
+const RECEIPT_FIELDS = ['recovery_emailed', 'recovery_emailed_at'];
+
+function commitRows(touched) {
+  const fresh = readRows();
+  const index = new Map(fresh.map((r, i) => [r.id, i]));
+  const skipped = [];
+  for (const t of touched) {
+    const i = index.get(t.id);
+    if (i == null) { skipped.push({ id: t.id, reason: 'row_disappeared' }); continue; }
+    const current = fresh[i];
+    const patch = {};
+    // Receipts are always safe to record: they state what we already sent.
+    for (const f of RECEIPT_FIELDS) if (t[f] !== undefined) patch[f] = t[f];
+    // The service owns the decision. If it decided this row while we were awaiting,
+    // keep the receipts but drop our linkage rather than overwrite its outcome.
+    if (current.status !== 'pending' && t.status === 'pending') {
+      skipped.push({ id: t.id, reason: `service_decided_${current.status}_link_dropped` });
+      fresh[i] = { ...current, ...patch };
+      continue;
+    }
+    for (const f of LINK_FIELDS) {
+      if (t[f] === undefined) continue;
+      // Never clobber a customer id the service resolved itself.
+      if (f === 'shopify_customer_id' && current[f] && String(current[f]) !== String(t[f])) {
+        skipped.push({ id: t.id, reason: 'customer_id_conflict' });
+        patch.shopify_customer_id = undefined;
+        continue;
+      }
+      patch[f] = t[f];
+    }
+    fresh[i] = { ...current, ...patch };
+  }
+  writeRows(fresh);
+  if (skipped.length) {
+    console.log(`  [merge] ${skipped.length} row(s) left to the service: ` +
+      skipped.map((x) => `${x.id}:${x.reason}`).join(', '));
+  }
+  return { written: fresh.length, skipped };
+}
 function firstLast(app) {
   const contact = app.contact_name || app.name || '';
   const firstName = app.first_name || (contact ? String(contact).split(' ')[0] : '');
@@ -101,7 +159,7 @@ async function sendOnly() {
   if (!targets.length) { console.log('Nothing to email.'); return; }
   let sent = 0;
   for (const app of targets) { if (await sendForApp(app)) sent++; await sleep(DELAY_MS); }
-  if (sent > 0) { writeRows(rows); console.log(`\nSent ${sent}; recovery_emailed stamped + jsonl updated.`); }
+  if (sent > 0) { commitRows(targets); console.log(`\nSent ${sent}; recovery_emailed stamped + jsonl updated (merged onto a fresh read).`); }
   else console.log(`\nNo real sends (DRY_RUN preview) — jsonl untouched, flags preserved for a real run.`);
 }
 
@@ -157,7 +215,7 @@ async function main() {
   const ts = new Date().toISOString().replace(/[-:]/g, '').replace(/\..+/, '');
   const jsonlBak = FILE + '.recovery-bak-' + ts;
   fs.copyFileSync(FILE, jsonlBak);
-  writeRows(rows);
+  commitRows(batch);
   const mapPath = path.join(path.dirname(FILE), `recovery-${ts}.json`);
   fs.writeFileSync(mapPath, JSON.stringify({ ts, file: FILE, jsonl_backup: jsonlBak, count: recovered.length, recovered }, null, 2));
   console.log(`\nLinked ${recovered.length}. jsonl backup: ${jsonlBak}  recovery map (rollback): ${mapPath}`);
@@ -169,7 +227,7 @@ async function main() {
       if (await sendForApp(app)) sent++;
       await sleep(DELAY_MS);
     }
-    if (sent > 0) { writeRows(rows); console.log(`  emailed ${sent}; recovery_emailed stamped + jsonl updated.`); }
+    if (sent > 0) { commitRows(recovered.map((rec) => rows.find((a) => a.id === rec.app_id)).filter(Boolean)); console.log(`  emailed ${sent}; recovery_emailed stamped + jsonl updated (merged onto a fresh read).`); }
   } else {
     console.log(`No emails sent (--send-emails not set). Apps are LINKED and now approvable at /admin/trade.`);
   }
diff --git a/verification/tk11285/control.json b/verification/tk11285/control.json
new file mode 100644
index 0000000..9d8c746
--- /dev/null
+++ b/verification/tk11285/control.json
@@ -0,0 +1,12 @@
+{
+  "mode": "CONTROL (no second writer)",
+  "approve_returned_ok": true,
+  "approve_status_returned": "approved",
+  "rows_before": 6,
+  "rows_after": 7,
+  "new_intake_id": "TRADE-20260910-85f58e",
+  "new_intake_survived": true,
+  "seed1_status_after": "approved",
+  "seed1_decision_survived": true,
+  "VERDICT": "NO LOSS"
+}
diff --git a/verification/tk11285/race-after.json b/verification/tk11285/race-after.json
new file mode 100644
index 0000000..1441c08
--- /dev/null
+++ b/verification/tk11285/race-after.json
@@ -0,0 +1,12 @@
+{
+  "mode": "RACE (recover-stuck-apps.js --send-only concurrent)",
+  "approve_returned_ok": true,
+  "approve_status_returned": "approved",
+  "rows_before": 6,
+  "rows_after": 7,
+  "new_intake_id": "TRADE-20260910-14b0e3",
+  "new_intake_survived": true,
+  "seed1_status_after": "approved",
+  "seed1_decision_survived": true,
+  "VERDICT": "NO LOSS"
+}
diff --git a/verification/tk11285/race-before.json b/verification/tk11285/race-before.json
new file mode 100644
index 0000000..1c9a4ac
--- /dev/null
+++ b/verification/tk11285/race-before.json
@@ -0,0 +1,12 @@
+{
+  "mode": "RACE (recover-stuck-apps.js --send-only concurrent)",
+  "approve_returned_ok": true,
+  "approve_status_returned": "approved",
+  "rows_before": 6,
+  "rows_after": 6,
+  "new_intake_id": "TRADE-20260910-b30200",
+  "new_intake_survived": false,
+  "seed1_status_after": "pending",
+  "seed1_decision_survived": false,
+  "VERDICT": "DATA LOSS"
+}
diff --git a/verification/tk11285/race.js b/verification/tk11285/race.js
new file mode 100644
index 0000000..2745632
--- /dev/null
+++ b/verification/tk11285/race.js
@@ -0,0 +1,74 @@
+'use strict';
+// TK-11285 preflight repro: does the shipped in-process decision lock protect
+// data/trade-applications.jsonl from the OTHER writer, scripts/recover-stuck-apps.js?
+// Both sides are REAL production code. Only lib/email + lib/shopify are stubbed
+// (zero external calls). Run: node -r ./repro/stubs.js repro/race.js [--control]
+const fs = require('fs');
+const path = require('path');
+const { spawn } = require('child_process');
+const ROOT = path.join(__dirname, '..', '..');
+const trade = require(path.join(ROOT, 'lib', 'trade'));
+
+const CONTROL = process.argv.includes('--control');
+const APPS = trade.APPS_PATH;
+const sleep = ms => new Promise(r => setTimeout(r, ms));
+const N = 6;
+
+function seed() {
+  const rows = [];
+  for (let i = 1; i <= N; i++) rows.push({
+    id: `TRADE-SEED-${i}`, email: `seed${i}@example.com`, business_name: `Seed ${i}`,
+    resale_cert: '', phone: '', extra: {}, shopify_customer_id: '5551111',
+    link_status: 'linked', link_via: 'existing', status: 'pending',
+    created_at: `2026-09-01T00:00:0${i}.000Z`, decided_at: null, decision: null, assigned_rep: null,
+  });
+  fs.mkdirSync(path.dirname(APPS), { recursive: true });
+  fs.writeFileSync(APPS, rows.map(r => JSON.stringify(r)).join('\n') + '\n');
+}
+const read = () => fs.readFileSync(APPS, 'utf8').split('\n').filter(Boolean).map(l => JSON.parse(l));
+
+(async () => {
+  seed();
+  const before = read();
+  let child = null;
+  if (!CONTROL) {
+    // The OTHER writer: real scripts/recover-stuck-apps.js --send-only, separate PROCESS.
+    child = spawn(process.execPath, ['-r', path.join(__dirname, 'stubs.js'),
+      path.join(ROOT, 'scripts', 'recover-stuck-apps.js'),
+      '--send-only', '--limit', String(N), '--delay', '50'],
+      { cwd: ROOT, env: { ...process.env, DRY_RUN: '0', REPRO_SEND_MS: '250' }, stdio: ['ignore', 'pipe', 'pipe'] });
+    let childOut = '';
+    const snapshotTaken = new Promise(res => {
+      child.stdout.on('data', d => { childOut += d; if (/LINKED not-yet-emailed=/.test(childOut)) res(); });
+    });
+    child.stderr.on('data', d => process.stderr.write('[child] ' + d));
+    // Deterministic: wait until the child has ACTUALLY taken its snapshot (it prints the
+    // target count right after readRows()), so the interleaving is not timing luck.
+    await snapshotTaken;
+    console.log('[t] child snapshot taken; live service now acts inside the window');
+  }
+
+  // --- the live service does its work DURING that window ---
+  const fresh = trade.apply({ email: 'newdesigner@example.com', business_name: 'Arrived During Window' });
+  const approveRes = await trade.approve('TRADE-SEED-1');
+
+  if (child) await new Promise(r => child.on('exit', r));
+  const after = read();
+
+  const newApp = after.find(r => r.id === fresh.id);
+  const seed1 = after.find(r => r.id === 'TRADE-SEED-1');
+  const out = {
+    mode: CONTROL ? 'CONTROL (no second writer)' : 'RACE (recover-stuck-apps.js --send-only concurrent)',
+    approve_returned_ok: approveRes.ok === true,
+    approve_status_returned: approveRes.status || null,
+    rows_before: before.length, rows_after: after.length,
+    new_intake_id: fresh.id,
+    new_intake_survived: !!newApp,
+    seed1_status_after: seed1 ? seed1.status : '<row missing>',
+    seed1_decision_survived: !!(seed1 && seed1.status === 'approved'),
+  };
+  out.VERDICT = (out.new_intake_survived && out.seed1_decision_survived)
+    ? 'NO LOSS' : 'DATA LOSS';
+  console.log(JSON.stringify(out, null, 2));
+  fs.writeFileSync(path.join(__dirname, CONTROL ? 'control.json' : 'race.json'), JSON.stringify(out, null, 2) + '\n');
+})();
diff --git a/verification/tk11285/race.json b/verification/tk11285/race.json
new file mode 100644
index 0000000..1441c08
--- /dev/null
+++ b/verification/tk11285/race.json
@@ -0,0 +1,12 @@
+{
+  "mode": "RACE (recover-stuck-apps.js --send-only concurrent)",
+  "approve_returned_ok": true,
+  "approve_status_returned": "approved",
+  "rows_before": 6,
+  "rows_after": 7,
+  "new_intake_id": "TRADE-20260910-14b0e3",
+  "new_intake_survived": true,
+  "seed1_status_after": "approved",
+  "seed1_decision_survived": true,
+  "VERDICT": "NO LOSS"
+}
diff --git a/verification/tk11285/stubs.js b/verification/tk11285/stubs.js
new file mode 100644
index 0000000..f0ca265
--- /dev/null
+++ b/verification/tk11285/stubs.js
@@ -0,0 +1,38 @@
+'use strict';
+// Repro harness stub loader. Intercepts lib/email + lib/shopify so the REAL
+// production code paths run with ZERO external calls (no George send, no Shopify).
+// lib/trade.js and scripts/recover-stuck-apps.js are NOT stubbed - they are the
+// code under test and run verbatim.
+const Module = require('module');
+const path = require('path');
+const origLoad = Module._load;
+const SEND_MS = parseInt(process.env.REPRO_SEND_MS || '250', 10);
+const sleep = ms => new Promise(r => setTimeout(r, ms));
+
+const emailStub = {
+  // Simulates a REAL (non-dryRun) George send that takes time - this is the
+  // read->write window that the recover script holds its stale snapshot across.
+  async sendEmail() { await sleep(SEND_MS); return { ok: true, status: 200, dryRun: false }; },
+  designerAccountReadyEmail: () => ({ subject: 's', html: 'h' }),
+  tradeApplicationEmail: () => ({ subject: 's', html: 'h' }),
+  repNotifyEmail: () => ({ subject: 's', html: 'h' }),
+  tradeApprovedEmail: () => ({ subject: 's', html: 'h' }),
+  repAssignmentEmail: () => ({ subject: 's', html: 'h' }),
+  tradeRejectedEmail: () => ({ subject: 's', html: 'h' }),
+};
+const shopifyStub = {
+  async findCustomerByEmail() { return '5551111'; },
+  async findOrCreateCustomer() { return { ok: true, id: '5551111', via: 'existing', created: false }; },
+  async addTags(id) { return { ok: true, status: 200, json: { customer: { id, tags: 'trade,trade_approved' } } }; },
+  async setCustomerMetafield(id, mf) { return { ok: true, status: 200, json: { metafield: { id: 'gid://shopify/Metafield/1', namespace: 'custom', key: 'assigned_rep', value: mf.value, type: mf.type, owner_id: id } } }; },
+  async getCustomer(id) { return { ok: true, status: 200, json: { customer: { id, tags: 'trade,trade_approved', metafields: [] } } }; },
+  async graphql() { return { ok: true, status: 200, json: { data: {} } }; },
+};
+Module._load = function (request, parent, isMain) {
+  const resolved = (() => { try { return Module._resolveFilename(request, parent, isMain); } catch { return ''; } })();
+  const base = path.basename(resolved);
+  const dir = path.basename(path.dirname(resolved));
+  if (dir === 'lib' && base === 'email.js') return emailStub;
+  if (dir === 'lib' && base === 'shopify.js') return shopifyStub;
+  return origLoad.apply(this, arguments);
+};

← 33dd248 TK-11361: soften attribution claim to match evidence strengt  ·  back to Dw Signup Fulfillment  ·  TK-10836: Option D complete — the $0.00 free-shipping rate W 251724b →