`scripts/tk11114-logging-test.js`

97 lines
'use strict';
// TK-11114 focused test: prove the un-swallow fix.
//  - On a George FAILURE (401), verify.startVerification returns ok:false with a REASON
//    (reason:'send_failed', status, error) AND the [email]/[verify] logs surface the status
//    — but NEVER leak the Basic-auth password or the send token (credential-safe).
//  - On George SUCCESS (200), it returns ok:true and logs "sent via George".
// Self-contained: a stub George on 127.0.0.1 (no network, no real email, no Shopify).

const http = require('http');
const assert = require('assert');

const SECRET_PASS = 'SUPERSECRETPASS_do_not_log_123';
const SECRET_TOKEN = 'SENDTOKEN_do_not_log_456';

function withStub(statusCode, body, run) {
  return new Promise((resolve, reject) => {
    const srv = http.createServer((req, res) => {
      let d = ''; req.on('data', c => d += c);
      req.on('end', () => { res.writeHead(statusCode, { 'Content-Type': 'application/json' }); res.end(JSON.stringify(body)); });
    });
    srv.listen(0, '127.0.0.1', async () => {
      const port = srv.address().port;
      try { const r = await run(port); srv.close(() => resolve(r)); }
      catch (e) { srv.close(() => reject(e)); }
    });
  });
}

// Capture console output for the duration of one call.
function captureConsole(fn) {
  const lines = [];
  const origLog = console.log, origWarn = console.warn, origErr = console.error;
  console.log = (...a) => lines.push(a.join(' '));
  console.warn = (...a) => lines.push(a.join(' '));
  console.error = (...a) => lines.push(a.join(' '));
  return Promise.resolve()
    .then(fn)
    .then((v) => { console.log = origLog; console.warn = origWarn; console.error = origErr; return { value: v, out: lines.join('\n') }; })
    .catch((e) => { console.log = origLog; console.warn = origWarn; console.error = origErr; throw e; });
}

async function loadVerifyPointedAt(port) {
  // Set env BEFORE requiring config so it resolves to the stub + a live (DRY_RUN=0) send path.
  process.env.DRY_RUN = '0';
  process.env.GEORGE_URL = `http://127.0.0.1:${port}`;
  process.env.DW_SIGNUP_VERIFY_SECRET = 'tk11114-test-secret';
  process.env.GEORGE_BASIC_AUTH = `testuser:${SECRET_PASS}`;
  process.env.GEORGE_EXTERNAL_SEND_TOKEN = SECRET_TOKEN;
  // Fresh module instances so the env above is read at load.
  for (const m of ['../lib/config', '../lib/email', '../lib/verify']) delete require.cache[require.resolve(m)];
  return require('../lib/verify');
}

async function main() {
  let failures = 0;
  const fail = (msg) => { console.error('  FAIL:', msg); failures++; };
  const pass = (msg) => console.log('  PASS:', msg);

  // ---- Case 1: George 401 (the real bug shape) ----
  await withStub(401, { ok: false, error: 'unauthorized' }, async (port) => {
    const { value: res, out } = await captureConsole(async () => {
      const verify = await loadVerifyPointedAt(port);
      return verify.startVerification({ email: 'buyer@example.com', customerId: '123', firstName: 'Test' });
    });
    try {
      assert.strictEqual(res.ok, false, 'result.ok should be false on 401'); pass('401 → ok:false');
      assert.strictEqual(res.reason, 'send_failed', 'reason should be send_failed'); pass('401 → reason:send_failed (propagated, not swallowed)');
      assert.strictEqual(res.status, 401, 'status should be 401'); pass('401 → status:401 surfaced');
      assert.ok(/SEND FAILED via George/.test(out), 'email.js must log SEND FAILED'); pass('[email] logged SEND FAILED');
      assert.ok(/status=401/.test(out), 'log must include status=401'); pass('log includes status=401');
      assert.ok(/verify-email SEND FAILED/.test(out), 'verify.js must warn'); pass('[verify] logged the failure reason');
      // CREDENTIAL SAFETY — the secret pass + token must NOT appear anywhere in the logs.
      assert.ok(!out.includes(SECRET_PASS), 'Basic-auth password must NOT be logged'); pass('no Basic-auth password in logs');
      assert.ok(!out.includes(SECRET_TOKEN), 'send token must NOT be logged'); pass('no send token in logs');
      assert.ok(!/verify\?token=/.test(out), 'verify token URL must NOT be logged'); pass('no verify token URL in logs');
    } catch (e) { fail(e.message); }
  });

  // ---- Case 2: George 200 (happy path) ----
  await withStub(200, { ok: true, id: 'msg_1' }, async (port) => {
    const { value: res, out } = await captureConsole(async () => {
      const verify = await loadVerifyPointedAt(port);
      return verify.startVerification({ email: 'buyer@example.com', customerId: '123', firstName: 'Test' });
    });
    try {
      assert.strictEqual(res.ok, true, 'result.ok should be true on 200'); pass('200 → ok:true');
      assert.ok(/sent via George/.test(out), 'should log a success line'); pass('[email] logged success');
      assert.ok(!out.includes(SECRET_PASS) && !out.includes(SECRET_TOKEN), 'no secrets on success path'); pass('no secrets in success logs');
    } catch (e) { fail(e.message); }
  });

  if (failures) { console.error(`\nTK-11114 logging test: ${failures} FAILURE(S)`); process.exit(1); }
  console.log('\nTK-11114 logging test: ALL PASS');
}

main().catch((e) => { console.error('test crashed:', e); process.exit(1); });