vyndr/tests/unit/acquisitionTrace.test.js

'use strict';

/**
 * SCHEDULED ACQUISITION OBSERVABILITY.
 *
 * The MLB snapshot stopped producing anything at the 22:00 and 01:00 slots on
 * 2026-08-27 while NBA/WNBA ran normally. The differential narrowed it to two
 * `runSnapshot` exits — `getOdds` THREW, or it RETURNED ZERO PROPS — and
 * production retained nothing that could tell them apart: a failed acquisition
 * has no snapshot_id, writes no ledger row and updates no slate.
 *
 * These tests prove the trace records the decision chain the existing control
 * flow already makes, and that it changes nothing about acquisition.
 */

const fs = require('fs');
const path = require('path');
const acq = require('../../src/services/ops/acquisitionTrace');
const snap = require('../../src/services/snapshotService');
const ROOT = path.resolve(__dirname, '..', '..');

jest.setTimeout(15000);

// Deps that stop runSnapshot at the acquisition boundary: no grading, no
// retention, no network. The trace is finalized BEFORE any of this, so these
// only keep the test from running the whole pipeline.
const HALT = {
  gradeAndCacheSlate: async () => ({ written: false, count: 0 }),
  retention: null,
  ledger: { recordPipelineGrades: async () => {}, captureClosing: async () => {}, gameDateFor: () => '2026-08-28' },
  captureBookPrices: async () => {},
  buildEspnIndex: async () => ({}),
};

const baseDeps = (over = {}) => ({
  notify: async () => {}, sleep: async () => {}, retryDelayMs: 0,
  now: () => '2026-08-28T03:00:00.000Z',
  scheduledHourUtc: 3, processStartedAt: '2026-08-28T00:31:17.657Z',
  retention: require('../../src/services/retentionService'),
  cacheGet: async () => null, cacheSet: async () => {},
  ...over,
});

/** Run runSnapshot and return the trace it persisted (if any). */
async function runWithTrace(sport, getOdds, over = {}) {
  const stored = [];
  const result = await snap.runSnapshot(sport, baseDeps({
    getOdds, persistAcquisitionTrace: async (t) => { stored.push(t); return { stored: true }; }, ...over,
  }));
  return { result, trace: stored[0] || null, stored };
}

const threw = (msg, extra = {}) => async () => { const e = new Error(msg); Object.assign(e, extra); throw e; };
const returns = (props, o = {}) => async () => ({ sport: 'mlb', props, provider: 'propline', source: 'live', ...o });

describe('ATTEMPT IDENTITY', () => {
  test('every attempt gets a unique diagnostic id, distinct from every other identity', () => {
    const a = acq.newAttemptId(); const b = acq.newAttemptId();
    expect(a).not.toBe(b);
    expect(a.startsWith('acq_')).toBe(true);
  });

  test('the trace carries sport, trigger, slot, start, code_sha and process generation', async () => {
    const { trace } = await runWithTrace('mlb', returns([]));
    expect(trace.sport).toBe('mlb');
    expect(trace.trigger).toBe(acq.TRIGGER.SCHEDULED);
    expect(trace.scheduled_hour_utc).toBe(3);
    expect(trace.started_at).toBe('2026-08-28T03:00:00.000Z');
    expect(trace).toHaveProperty('code_sha');
    expect(trace.process_generation).toBe('2026-08-28T00:31:17.657Z');
  });

  test('it does NOT reuse or alter any product identity', () => {
    const t = acq.begin({ sport: 'mlb' });
    for (const forbidden of ['snapshot_id', 'read_id', 'claim_digest', 'canonical_event_id', 'ledger_id', 'publication_id']) {
      expect(t).not.toHaveProperty(forbidden);
    }
  });
});

describe('THE TEST MATRIX — one scheduled acquisition', () => {
  test('PRIMARY NONZERO -> runSnapshot continues, no fallback invented', async () => {
    // wnba: no MLB event-identity branch, so this stops at the acquisition
    // boundary without reaching statsapi.
    const { result, trace } = await runWithTrace('wnba', returns([{ player: 'x' }, { player: 'y' }]), HALT);
    expect(trace.final).toBe(acq.FINAL.NONZERO);
    expect(trace.final_props_count).toBe(2);
    expect(trace.outcome).toBe(acq.OUTCOME.CONTINUED);
    expect(trace.attempts).toHaveLength(1);
    expect(result.status).not.toBe('error');
    expect(trace.sport).toBe('wnba');
  });

  test('FINAL ZERO -> EARLY_RETURN_ZERO_PROPS, recorded distinctly from an error', async () => {
    const { result, trace } = await runWithTrace('mlb', returns([]));
    expect(trace.final).toBe(acq.FINAL.ZERO);
    expect(trace.final_props_count).toBe(0);
    expect(trace.outcome).toBe(acq.OUTCOME.EARLY_RETURN_ZERO_PROPS);
    expect(trace.final).not.toBe(acq.FINAL.THREW);
    expect(result.status).toBe('skipped');
    expect(result.reason).toBe('no props');
  });

  test('FINAL THROW -> EARLY_RETURN_ODDS_ERROR, with BOTH attempts preserved', async () => {
    const { result, trace } = await runWithTrace('mlb', threw('Odds data temporarily unavailable.', { statusCode: 429 }));
    expect(trace.final).toBe(acq.FINAL.THREW);
    expect(trace.outcome).toBe(acq.OUTCOME.EARLY_RETURN_ODDS_ERROR);
    // The EXISTING retry — primary + retry, not an added one.
    expect(trace.attempts).toHaveLength(2);
    expect(trace.attempts[0].is_retry).toBe(false);
    expect(trace.attempts[1].is_retry).toBe(true);
    expect(trace.attempts.every((a) => a.result.result === 'THREW')).toBe(true);
    expect(result.status).toBe('error');
  });

  test('PRIMARY ERROR -> EXISTING RETRY SUCCESS: both attempts preserved, final NONZERO', async () => {
    let n = 0;
    const getOdds = async () => {
      n += 1;
      if (n === 1) throw new Error('transient');
      return { sport: 'wnba', props: [{ player: 'x' }], provider: 'propline', source: 'live' };
    };
    const { trace } = await runWithTrace('wnba', getOdds, HALT);
    expect(trace.attempts).toHaveLength(2);
    expect(trace.attempts[0].result.result).toBe('THREW');
    expect(trace.attempts[1].result.result).toBe('RETURNED');
    expect(trace.final).toBe(acq.FINAL.NONZERO);
    expect(trace.outcome).toBe(acq.OUTCOME.CONTINUED);
  });

  test('the recorded retry delay is the CONFIGURED one, never an added retry', async () => {
    const { trace } = await runWithTrace('mlb', threw('x'), { retryDelayMs: 60000 });
    expect(trace.attempts[1].configured_delay_ms).toBe(60000);
    const src = fs.readFileSync(path.join(ROOT, 'src/services/snapshotService.js'), 'utf8');
    // Exactly two getOdds calls and exactly one retry sleep — unchanged.
    expect((src.match(/deps\.getOdds\(/g) || [])).toHaveLength(2);
    expect((src.match(/deps\.sleep\(deps\.retryDelayMs\)/g) || [])).toHaveLength(1);
  });
});

describe('THE DECISION CHAIN INSIDE getOdds', () => {
  const chain = () => {
    const t = acq.begin({ sport: 'mlb' });
    acq.beginAttempt(t, { index: 0 });
    return { t, rec: acq.recorder(t) };
  };

  test('PRIMARY ZERO -> RETRY ZERO -> FALLBACK BLOCKED records the exact chain', () => {
    const { t, rec } = chain();
    rec.cache({ considered: true, hit: false, decision: 'miss' });
    rec.primary({ provider: 'propline', attempted: true, outcome: 'ZERO', count: 0 });
    rec.fallback({
      provider: 'odds-api', considered: true, allowed_at_invocation: false,
      blocked_reason: 'quota_ceiling',
      quota_at_invocation: { used: 478, limit: 500, pct: 0.956, period: '2026-08' },
      attempted: false,
    });
    acq.finishAttempt(t, { result: 'THREW', error: 'Odds data temporarily unavailable.' });
    const a = t.attempts[0];
    expect(a.cache.hit).toBe(false);
    expect(a.primary.outcome).toBe('ZERO');
    expect(a.primary.count).toBe(0);
    expect(a.fallback.allowed_at_invocation).toBe(false);
    expect(a.fallback.blocked_reason).toBe('quota_ceiling');
    expect(a.fallback.quota_at_invocation.used).toBe(478);
    expect(a.fallback.attempted).toBe(false);
  });

  test('PRIMARY ERROR is recorded distinctly from PRIMARY ZERO', () => {
    const { t, rec } = chain();
    rec.primary({ provider: 'propline', attempted: true, outcome: 'ERROR', count: null, error: 'socket hang up' });
    expect(t.attempts[0].primary.outcome).toBe('ERROR');
    expect(t.attempts[0].primary.outcome).not.toBe('ZERO');
    expect(t.attempts[0].primary.count).toBeNull();
  });

  test('FALLBACK SUCCESS is recorded when the existing behaviour reaches it', () => {
    const { t, rec } = chain();
    rec.primary({ provider: 'propline', attempted: true, outcome: 'ZERO', count: 0 });
    rec.fallback({ provider: 'odds-api', considered: true, allowed_at_invocation: true, attempted: true, outcome: 'NONZERO', count: 120 });
    expect(t.attempts[0].fallback.outcome).toBe('NONZERO');
    expect(t.attempts[0].fallback.count).toBe(120);
  });

  test('quota is captured AT INVOCATION, inside getOdds, not read later', () => {
    const src = fs.readFileSync(path.join(ROOT, 'src/services/oddsService.js'), 'utf8');
    const i = src.indexOf("const quotaStatus = await quotaTracker.getQuotaStatus('odds-api');");
    expect(i).toBeGreaterThan(-1);
    const block = src.slice(i, i + 900);
    expect(block).toMatch(/quota_at_invocation/);
    expect(block).toMatch(/allowed_at_invocation: !!quotaStatus\.allowed/);
  });

  test('the recorder is a pure write — a no-op recorder leaves behaviour identical', async () => {
    const src = fs.readFileSync(path.join(ROOT, 'src/services/oddsService.js'), 'utf8');
    expect(src).toMatch(/const NO_TRACE = Object\.freeze\(\{ cache\(\) \{\}, primary\(\) \{\}, fallback\(\) \{\} \}\)/);
    expect(src).toMatch(/const trace = \(opts && opts\.trace\) \|\| NO_TRACE;/);
    // No trace call may appear inside a conditional test.
    expect(src).not.toMatch(/if\s*\([^)]*trace\.[a-z]/);
  });
});

describe('THE OBSERVER MAKES NO PROVIDER CALL', () => {
  const oddsSrc = fs.readFileSync(path.join(ROOT, 'src/services/oddsService.js'), 'utf8');
  const traceSrc = fs.readFileSync(path.join(ROOT, 'src/services/ops/acquisitionTrace.js'), 'utf8');

  test('the trace module contains no HTTP or provider call whatsoever', () => {
    // Scan CODE, not prose or the sanitizer's own URL regex — a guard that
    // flags its own redaction pattern is checking the wrong thing.
    const code = traceSrc
      .replace(/\/\*[\s\S]*?\*\//g, '')
      .replace(/(^|[^:])\/\/.*$/gm, '$1')
      .replace(/s\.replace\([\s\S]*?\);/g, '');
    for (const forbidden of ['fetch(', 'axios', 'getProps', 'fetchAllOdds', 'gateway',
      "require('http", 'https://', 'getOdds', 'oddsService', 'proplineAdapter']) {
      expect(code).not.toContain(forbidden);
    }
  });

  test('instrumenting getOdds added no provider request', () => {
    expect((oddsSrc.match(/await propline\.getProps\(/g) || [])).toHaveLength(1);
    expect((oddsSrc.match(/await fetchAllOdds\(/g) || [])).toHaveLength(1);
  });

  test('the internal read endpoint runs no pipeline and no fetch', () => {
    const src = fs.readFileSync(path.join(ROOT, 'src/routes/internal.js'), 'utf8');
    const i = src.indexOf("router.get('/acquisition/:sport'");
    expect(i).toBeGreaterThan(-1);
    const block = src.slice(i, src.indexOf('});', src.indexOf('} catch', i)));
    expect(block).not.toMatch(/getOdds|runSnapshot|diagnose|fetch\(/);
    expect(block).toMatch(/acq\.history/);
  });
});

describe('SANITIZATION', () => {
  test('credentials, tokens and URLs never reach the trace', () => {
    const dirty = 'failed https://api.propline.io/v1/odds?apiKey=abcd1234abcd1234abcd1234 token=zzzzzzzzzzzzzzzzzzzzzzzzzz';
    const clean = acq.sanitize(dirty);
    expect(clean).not.toMatch(/abcd1234abcd1234/);
    expect(clean).not.toMatch(/api\.propline\.io/);
    expect(clean).not.toMatch(/zzzzzzzzzzzzzzzzzzzzzz/);
    expect(clean).toMatch(/\[url\]|\[redacted\]/);
  });

  test('a thrown provider error is sanitized on the way into the trace', async () => {
    const { trace } = await runWithTrace('mlb', threw('boom https://x.io/y?key=SUPERSECRETKEYVALUE123456'));
    const blob = JSON.stringify(trace);
    expect(blob).not.toMatch(/SUPERSECRETKEYVALUE/);
    expect(blob).not.toMatch(/x\.io/);
  });

  test('no prop payload is retained — counts only', async () => {
    const { trace } = await runWithTrace('mlb', returns([{ player: 'Aaron Judge', stat: 'hits' }]));
    expect(JSON.stringify(trace)).not.toMatch(/Aaron Judge/);
    expect(trace.final_props_count).toBe(1);
  });
});

describe('HISTORY IS BOUNDED, PER SPORT, AND SCHEDULED-ONLY', () => {
  test('storage is a bounded per-sport list with a TTL', () => {
    expect(acq.key('mlb')).toBe('ops:acquisition:mlb');
    expect(acq.key('wnba')).not.toBe(acq.key('mlb'));
    expect(acq.HISTORY_CAP).toBeGreaterThan(1);
    expect(acq.HISTORY_CAP).toBeLessThanOrEqual(20);
    expect(acq.TTL_SECONDS).toBeGreaterThanOrEqual(86400);
  });

  test('it uses ATOMIC append (lpush/ltrim), so two schedulers cannot overwrite each other', async () => {
    const calls = [];
    const client = {
      lpush: async (k, v) => { calls.push(['lpush', k, JSON.parse(v).snapshot_attempt_id]); },
      ltrim: async (k, a, b) => calls.push(['ltrim', k, a, b]),
      expire: async (k, t) => calls.push(['expire', k, t]),
    };
    const a = acq.finish(acq.begin({ sport: 'mlb' }), { final: acq.FINAL.THREW });
    const b = acq.finish(acq.begin({ sport: 'mlb' }), { final: acq.FINAL.THREW });
    await acq.persist(a, { getRedisClient: () => client });
    await acq.persist(b, { getRedisClient: () => client });
    expect(calls.filter((c) => c[0] === 'lpush')).toHaveLength(2);
    expect(calls.filter((c) => c[0] === 'ltrim')).toHaveLength(2);
    // Read-modify-write would show a get; there is none.
    expect(calls.some((c) => c[0] === 'get' || c[0] === 'set')).toBe(false);
    const src = fs.readFileSync(path.join(ROOT, 'src/services/ops/acquisitionTrace.js'), 'utf8');
    expect(src).toMatch(/client\.lpush/);
    expect(src).not.toMatch(/cacheSet\(/);
  });

  test('INTRADAY SUCCESS CANNOT OVERWRITE A SCHEDULED FAILURE', async () => {
    // Structural: intraday never calls runSnapshot, and persist refuses any
    // non-scheduled trigger outright.
    const intraday = acq.finish(acq.begin({ sport: 'mlb', trigger: acq.TRIGGER.INTRADAY }), { final: acq.FINAL.NONZERO });
    const client = { lpush: async () => { throw new Error('must not be called'); }, ltrim: async () => {}, expire: async () => {} };
    const out = await acq.persist(intraday, { getRedisClient: () => client });
    expect(out.stored).toBe(false);
    expect(out.reason).toBe('not_retained_trigger');
    const src = fs.readFileSync(path.join(ROOT, 'src/services/intradayRefreshService.js'), 'utf8');
    expect(src).not.toMatch(/runSnapshot/);
  });

  test('ANOTHER SPORT CANNOT OVERWRITE MLB EVIDENCE', async () => {
    const keys = [];
    const client = { lpush: async (k) => keys.push(k), ltrim: async () => {}, expire: async () => {} };
    for (const sp of ['mlb', 'nba', 'wnba']) {
      await acq.persist(acq.finish(acq.begin({ sport: sp }), { final: acq.FINAL.ZERO }), { getRedisClient: () => client });
    }
    expect(new Set(keys).size).toBe(3);
    expect(keys).toContain('ops:acquisition:mlb');
  });

  test('two schedulers on the SAME slot are retained separately', async () => {
    const stored = [];
    const client = { lpush: async (k, v) => stored.push(JSON.parse(v)), ltrim: async () => {}, expire: async () => {} };
    for (const gen of ['proc-A', 'proc-B']) {
      const t = acq.begin({ sport: 'mlb', scheduledHourUtc: 3, processStartedAt: gen });
      await acq.persist(acq.finish(t, { final: acq.FINAL.ZERO }), { getRedisClient: () => client });
    }
    expect(stored).toHaveLength(2);
    expect(stored[0].snapshot_attempt_id).not.toBe(stored[1].snapshot_attempt_id);
    expect(new Set(stored.map((t) => t.process_generation)).size).toBe(2);
  });
});

describe('TELEMETRY FAILURE MUST NOT BREAK THE PRODUCT', () => {
  test('a trace-store failure does not fail a healthy acquisition', async () => {
    const { result, stored } = await runWithTrace('wnba', returns([{ p: 1 }]), {
      ...HALT,
      persistAcquisitionTrace: async () => { throw new Error('redis down'); },
    });
    // The snapshot continued past acquisition; it did not return an odds error.
    expect(result.status).not.toBe('error');
    expect(stored).toHaveLength(0);
  });

  test('the default path never constructs a redis client under test', async () => {
    // The opsNotify precedent. Without it, every suite driving runSnapshot
    // would open a real connection and block.
    const out = await acq.persist(acq.finish(acq.begin({ sport: 'mlb' }), { final: acq.FINAL.ZERO }));
    expect(out.stored).toBe(false);
    expect(out.reason).toBe('test_env');
  });

  test('persist swallows a store error and reports it rather than throwing', async () => {
    const client = { lpush: async () => { throw new Error('redis down'); }, ltrim: async () => {}, expire: async () => {} };
    const out = await acq.persist(acq.finish(acq.begin({ sport: 'mlb' }), { final: acq.FINAL.ZERO }), { getRedisClient: () => client });
    expect(out.stored).toBe(false);
    expect(out.reason).toMatch(/redis down/);
  });

  test('the default persist dep is wrapped so it can never throw into runSnapshot', () => {
    const src = fs.readFileSync(path.join(ROOT, 'src/services/snapshotService.js'), 'utf8');
    const i = src.indexOf('persistAcquisitionTrace: opts.persistAcquisitionTrace');
    expect(i).toBeGreaterThan(-1);
    expect(src.slice(i, i + 220)).toMatch(/try \{[\s\S]*catch/);
  });
});

describe('ACQUISITION BEHAVIOUR IS UNCHANGED', () => {
  test('getOdds gained only an optional recorder argument', () => {
    const src = fs.readFileSync(path.join(ROOT, 'src/services/oddsService.js'), 'utf8');
    expect(src).toMatch(/async function getOdds\(sport, opts = \{\}\)/);
  });

  test('provider order, quota threshold and cache policy are untouched', () => {
    const src = fs.readFileSync(path.join(ROOT, 'src/services/oddsService.js'), 'utf8');
    // PropLine still first, still gated on hasKeys, still the >0 test.
    expect(src).toMatch(/if \(propline\.hasKeys\(\)\) \{/);
    expect(src).toMatch(/pl\.props\.length > 0/);
    expect(src).toMatch(/if \(!quotaStatus\.allowed\) \{/);
  });

  test('runSnapshot HONOURS the caller trigger — it is not hardcoded scheduled', async () => {
    // Without this, a non-scheduled acquisition would be stamped SCHEDULED and
    // could displace real scheduled evidence.
    const { trace } = await runWithTrace('mlb', returns([]), { trigger: acq.TRIGGER.INTRADAY });
    expect(trace.trigger).toBe(acq.TRIGGER.INTRADAY);
    expect(trace.trigger).not.toBe(acq.TRIGGER.SCHEDULED);
    const client = { lpush: async () => { throw new Error('must not be called'); }, ltrim: async () => {}, expire: async () => {} };
    expect((await acq.persist(trace, { getRedisClient: () => client })).reason).toBe('not_retained_trigger');
  });

  test('the scheduler passes only diagnostic context, not behaviour', () => {
    const src = fs.readFileSync(path.join(ROOT, 'src/snapshotScheduler.js'), 'utf8');
    const i = src.indexOf('const results = await runAll({');
    const block = src.slice(i, i + 320);
    expect(block).toMatch(/sports: scheduled/);
    expect(block).toMatch(/trigger: acq\.TRIGGER\.SCHEDULED/);
    expect(block).toMatch(/scheduledHourUtc: h/);
    expect(block).toMatch(/processStartedAt: PROCESS_STARTED_AT/);
    expect(block).not.toMatch(/retryDelayMs|getOdds|quota/);
  });
});