gstack/test/question-log-hook.test.ts

/**
 * PostToolUse hook (plan-tune cathedral T5) — unit tests.
 *
 * Feeds the hook synthetic Claude Code hook payloads via stdin and asserts
 * the resulting question-log.jsonl reflects the right schema. Covers:
 *   - Marker-first question_id (D18 progressive markers)
 *   - Hash fallback when no marker
 *   - source=hook tagging
 *   - source=auq-other when free_text present
 *   - Dedup on (source, tool_use_id) composite (D3)
 *   - Hook exits 0 even on malformed input (never blocks user session)
 *   - mcp__*__AskUserQuestion matcher acceptance
 *   - "(recommended)" label parse → recommended field populated
 *   - Refuse-on-ambiguous: two (recommended) labels → recommended omitted
 */

import { describe, test, expect, beforeEach, afterEach } from 'bun:test';
import * as fs from 'fs';
import * as path from 'path';
import * as os from 'os';
import { spawnSync } from 'child_process';
import { hookChildBudgetMs } from '../hosts/claude/hooks/spawn-bin';
import { launchSkipReason } from '../hosts/claude/hooks/question-log-hook.ts';

const ROOT = path.resolve(import.meta.dir, '..');
const HOOK = path.join(ROOT, 'hosts', 'claude', 'hooks', 'question-log-hook');

let stateRoot: string;

beforeEach(() => {
  stateRoot = fs.mkdtempSync(path.join(os.tmpdir(), 'gstack-hooklog-'));
  // Pre-create slug-resolved project dir so the bin's gstack-slug doesn't
  // recompute every time.
});

afterEach(() => {
  fs.rmSync(stateRoot, { recursive: true, force: true });
});

function runHook(stdin: object): { stdout: string; stderr: string; status: number } {
  const env: Record<string, string> = {};
  for (const [k, v] of Object.entries(process.env)) {
    if (v !== undefined) env[k] = v;
  }
  env.GSTACK_STATE_ROOT = stateRoot;
  delete env.GSTACK_HOME;
  env.GSTACK_QUESTION_LOG_NO_DERIVE = '1';
  const res = spawnSync(HOOK, [], {
    env,
    input: JSON.stringify(stdin),
    encoding: 'utf-8',
    cwd: ROOT,
    timeout: 30_000,
  });
  return {
    stdout: res.stdout ?? '',
    stderr: res.stderr ?? '',
    status: res.status ?? -1,
  };
}

function readLog(): Array<Record<string, unknown>> {
  const projectDirs = fs.existsSync(path.join(stateRoot, 'projects'))
    ? fs.readdirSync(path.join(stateRoot, 'projects'))
    : [];
  const all: Array<Record<string, unknown>> = [];
  for (const d of projectDirs) {
    const f = path.join(stateRoot, 'projects', d, 'question-log.jsonl');
    if (!fs.existsSync(f)) continue;
    const lines = fs.readFileSync(f, 'utf-8').trim().split('\n').filter(Boolean);
    for (const l of lines) {
      try {
        all.push(JSON.parse(l));
      } catch {
        // skip malformed
      }
    }
  }
  return all;
}

// ----------------------------------------------------------------------
// Native AskUserQuestion capture
// ----------------------------------------------------------------------

describe('PostToolUse hook (native AskUserQuestion)', () => {
  test('captures one event per question with source=hook and tool_use_id', () => {
    const r = runHook({
      session_id: 'sess1',
      hook_event_name: 'PostToolUse',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-1',
      tool_input: {
        questions: [
          {
            question: 'D1 — Test capture\nRecommendation: A',
            options: ['A) Accept (recommended)', 'B) Reject'],
            multiSelect: false,
          },
        ],
      },
      tool_response: {
        answers: [{ option_label: 'A) Accept (recommended)' }],
      },
      cwd: ROOT,
    });
    expect(r.status).toBe(0);
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].source).toBe('hook');
    expect(events[0].tool_use_id).toBe('tu-1');
    expect(events[0].session_id).toBe('sess1');
    expect(typeof events[0].question_id).toBe('string');
    expect((events[0].question_id as string).startsWith('hook-')).toBe(true);
    expect(events[0].user_choice).toContain('Accept');
    // Recommended parsed from (recommended) label
    expect(events[0].recommended).toContain('Accept');
  });

  test('marker-first question_id when <gstack-qid:foo> present', () => {
    runHook({
      session_id: 'sess2',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-2',
      tool_input: {
        questions: [
          {
            question: 'D2 — Marker test <gstack-qid:ship-test-failure-triage>\nRecommendation: A',
            options: ['A) Fix now (recommended)', 'B) Investigate', 'C) Ack and ship'],
          },
        ],
      },
      tool_response: { answers: [{ option_label: 'A) Fix now (recommended)' }] },
      cwd: ROOT,
    });
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].question_id).toBe('ship-test-failure-triage');
    // Marker stripped from summary
    expect((events[0].question_summary as string).includes('<gstack-qid:')).toBe(false);
  });

  test('a signal hint in the marker reaches the log row (#3442)', () => {
    runHook({
      session_id: 'sess-hint',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-hint',
      tool_input: {
        questions: [
          {
            question: 'D3 — Add caching? <gstack-qid:plan-ceo-review-add-caching;signal=scope-appetite>',
            options: ['A) Expand to add caching (recommended)', 'B) Hold scope'],
          },
        ],
      },
      tool_response: { answers: [{ option_label: 'A) Expand to add caching (recommended)' }] },
      cwd: ROOT,
    });
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].question_id).toBe('plan-ceo-review-add-caching');
    expect(events[0].signal_key).toBe('scope-appetite');
    expect(events[0].user_choice).toBe('expand');
    expect((events[0].question_summary as string).includes('gstack-qid')).toBe(false);
  });
});

// ----------------------------------------------------------------------
// Shape D: current native AUQ result — answers object keyed by question text
// ----------------------------------------------------------------------

describe('PostToolUse hook (Shape D: answers object keyed by question text)', () => {
  test('captures user_choice from the answers map, stripping the (Recommended) suffix', () => {
    const qText = 'D-shape test: apply the edits?';
    runHook({
      session_id: 'sessD1',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-d1',
      tool_input: {
        questions: [
          { question: qText, options: [{ label: 'Full revision (Recommended)' }, { label: 'Hold' }] },
        ],
      },
      tool_response: { answers: { [qText]: 'Full revision (Recommended)' } },
      cwd: ROOT,
    });
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].user_choice).toBe('Full revision');
    expect(events[0].recommended).toBe('Full revision');
    expect(events[0].followed_recommendation).toBe(true);
  });

  test('free-text answer (not an option label) → source=auq-other with free_text', () => {
    const qText = 'D-shape free text test';
    runHook({
      session_id: 'sessD2',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-d2',
      tool_input: {
        questions: [{ question: qText, options: [{ label: 'Alpha' }, { label: 'Beta' }] }],
      },
      tool_response: { answers: { [qText]: 'I cannot see what the proposal is' } },
      cwd: ROOT,
    });
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].source).toBe('auq-other');
    expect(events[0].free_text).toContain('cannot see');
  });

  test('annotations notes are captured as free_text alongside a selected option', () => {
    const qText = 'D-shape annotations test';
    runHook({
      session_id: 'sessD3',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-d3',
      tool_input: {
        questions: [{ question: qText, options: [{ label: 'Alpha' }, { label: 'Beta' }] }],
      },
      tool_response: {
        answers: { [qText]: 'Alpha' },
        annotations: { [qText]: { notes: 'but only after the demo' } },
      },
      cwd: ROOT,
    });
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].user_choice).toBe('Alpha');
    expect(events[0].free_text).toContain('after the demo');
  });

  test('empty tool_response → user_choice __unknown__ and NO followed_recommendation', () => {
    runHook({
      session_id: 'sessD4',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-d4',
      tool_input: {
        questions: [
          { question: 'D-shape unknown test', options: [{ label: 'Alpha (Recommended)' }, { label: 'Beta' }] },
        ],
      },
      cwd: ROOT,
    });
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].user_choice).toBe('__unknown__');
    expect(events[0].recommended).toBe('Alpha');
    expect(events[0].followed_recommendation).toBeUndefined();
  });
});

// ----------------------------------------------------------------------
// MCP AskUserQuestion variant (Conductor)
// ----------------------------------------------------------------------

describe('PostToolUse hook (mcp__*__AskUserQuestion variant)', () => {
  test('accepts mcp__conductor__AskUserQuestion tool_name', () => {
    const r = runHook({
      session_id: 'sess3',
      tool_name: 'mcp__conductor__AskUserQuestion',
      tool_use_id: 'tu-3',
      tool_input: {
        questions: [{ question: 'Test', options: ['A', 'B'] }],
      },
      tool_response: { answers: [{ option_label: 'A' }] },
      cwd: ROOT,
    });
    expect(r.status).toBe(0);
    expect(readLog().length).toBe(1);
  });

  test('ignores unrelated tool_name (defensive)', () => {
    const r = runHook({
      session_id: 'sess4',
      tool_name: 'Bash',
      tool_use_id: 'tu-4',
      tool_input: {},
      cwd: ROOT,
    });
    expect(r.status).toBe(0);
    expect(readLog().length).toBe(0);
  });
});

// ----------------------------------------------------------------------
// Free-text capture (Layer 8 dream cycle)
// ----------------------------------------------------------------------

describe('PostToolUse hook (free-text "Other" responses)', () => {
  test('source=auq-other and free_text populated when user types free text', () => {
    runHook({
      session_id: 'sess5',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-5',
      tool_input: {
        questions: [{ question: 'D5 — Other test', options: ['A', 'B'] }],
      },
      tool_response: {
        answers: [
          {
            option_label: 'Other',
            free_text: 'I always include tests with new features',
          },
        ],
      },
      cwd: ROOT,
    });
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].source).toBe('auq-other');
    expect(events[0].free_text).toContain('always include tests');
  });
});

// ----------------------------------------------------------------------
// Dedup
// ----------------------------------------------------------------------

describe('PostToolUse hook (dedup on source + tool_use_id)', () => {
  test('second fire with same (source, tool_use_id) is dropped', () => {
    const payload = {
      session_id: 'sess6',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-6',
      tool_input: { questions: [{ question: 'Dedup test', options: ['A'] }] },
      tool_response: { answers: [{ option_label: 'A' }] },
      cwd: ROOT,
    };
    runHook(payload);
    runHook(payload);
    expect(readLog().length).toBe(1);
  });
});

// ----------------------------------------------------------------------
// Refuse-on-ambiguous (D2 safety)
// ----------------------------------------------------------------------

describe('PostToolUse hook (recommended parser safety)', () => {
  test('two (recommended) labels → recommended field omitted', () => {
    runHook({
      session_id: 'sess7',
      tool_name: 'AskUserQuestion',
      tool_use_id: 'tu-7',
      tool_input: {
        questions: [
          {
            question: 'Ambiguous test',
            options: ['A) Foo (recommended)', 'B) Bar (recommended)'],
          },
        ],
      },
      tool_response: { answers: [{ option_label: 'A) Foo (recommended)' }] },
      cwd: ROOT,
    });
    const events = readLog();
    expect(events.length).toBe(1);
    expect(events[0].recommended).toBeUndefined();
  });
});

// ----------------------------------------------------------------------
// Crash safety
// ----------------------------------------------------------------------

describe('PostToolUse hook (crash safety)', () => {
  test('exits 0 on empty stdin', () => {
    const env: Record<string, string> = {};
    for (const [k, v] of Object.entries(process.env)) {
      if (v !== undefined) env[k] = v;
    }
    env.GSTACK_STATE_ROOT = stateRoot;
    env.GSTACK_QUESTION_LOG_NO_DERIVE = '1';
    const res = spawnSync(HOOK, [], { env, input: '', encoding: 'utf-8', timeout: 30_000 });
    expect(res.status).toBe(0);
  });

  test('exits 0 on malformed JSON', () => {
    const env: Record<string, string> = {};
    for (const [k, v] of Object.entries(process.env)) {
      if (v !== undefined) env[k] = v;
    }
    env.GSTACK_STATE_ROOT = stateRoot;
    env.GSTACK_QUESTION_LOG_NO_DERIVE = '1';
    const res = spawnSync(HOOK, [], {
      env,
      input: 'not json',
      encoding: 'utf-8',
      timeout: 30_000,
    });
    expect(res.status).toBe(0);
    // Error logged to hook-errors.log
    const errLog = path.join(stateRoot, 'hook-errors.log');
    expect(fs.existsSync(errLog)).toBe(true);
    expect(fs.readFileSync(errLog, 'utf-8')).toContain('stdin parse failed');
  });
});

// ----------------------------------------------------------------------
// One budget for every child (Claude Code kills the hook at 5 s)
// ----------------------------------------------------------------------

describe('PostToolUse hook (budget)', () => {
  test('every child shares the registered 5 s budget, less the exit reserve', () => {
    expect(hookChildBudgetMs(1_000, 1_000)).toBe(4_500);
    expect(hookChildBudgetMs(1_000, 3_000)).toBe(2_500);
    expect(hookChildBudgetMs(1_000, 6_000)).toBeLessThan(0);
  });

  test('a call launches only with at least 250 ms of budget left', () => {
    expect(launchSkipReason(4_500)).toBeNull();
    expect(launchSkipReason(250)).toBeNull();
    expect(launchSkipReason(249)).toBe("the hook's 5000 ms budget is spent (249 ms left, under the 250 ms a call needs)");
    expect(launchSkipReason(-40)).toBe("the hook's 5000 ms budget is spent (0 ms left, under the 250 ms a call needs)");
  });

  test('slow children stop at the hook budget and the skipped questions are logged', () => {
    const fakeBin = fs.mkdtempSync(path.join(os.tmpdir(), 'gstack-slow-bun-'));
    try {
      fs.writeFileSync(path.join(fakeBin, 'bun'), `#!/bin/sh\nsleep 5\nexec "${process.execPath}" "$@"\n`, { mode: 0o755 });
      const env: Record<string, string> = {};
      for (const [k, v] of Object.entries(process.env)) {
        if (v !== undefined) env[k] = v;
      }
      env.GSTACK_STATE_ROOT = stateRoot;
      delete env.GSTACK_HOME;
      env.GSTACK_QUESTION_LOG_NO_DERIVE = '1';
      env.PATH = `${fakeBin}${path.delimiter}${env.PATH ?? ''}`;
      const questions = Array.from({ length: 6 }, (_, i) => ({ question: `Budget question ${i}`, options: ['A', 'B'] }));
      const res = spawnSync(process.execPath, [path.join(ROOT, 'hosts', 'claude', 'hooks', 'question-log-hook.ts')], {
        env,
        input: JSON.stringify({
          session_id: 'budget',
          tool_name: 'AskUserQuestion',
          tool_use_id: 'tu-budget',
          tool_input: { questions },
          tool_response: { answers: questions.map(() => ({ option_label: 'A' })) },
          cwd: ROOT,
        }),
        encoding: 'utf-8',
        cwd: ROOT,
        timeout: 30_000,
      });
      expect(res.status).toBe(0);
      expect(readLog().length).toBeLessThan(questions.length);
      const errors = fs.readFileSync(path.join(stateRoot, 'hook-errors.log'), 'utf-8');
      expect(errors).toMatch(/exited null \(SIG\w+ after \d+ of \d+ ms\)/);
      expect(errors).toContain('budget is spent');
    } finally {
      fs.rmSync(fakeBin, { recursive: true, force: true });
    }
  }, 30_000);
});