|
| 1 | +/** |
| 2 | + * Regression tests for the SIGUSR1 throttle-counter race in observe.sh (#2296) |
| 3 | + * |
| 4 | + * observe.sh runs on every tool call and bumps a throttle counter in |
| 5 | + * ${PROJECT_DIR}/.observer-signal-counter so the observer is signaled only |
| 6 | + * every N observations (#521). The bump used a plain read-modify-write with no |
| 7 | + * locking, so concurrent hook invocations could read the same value, both |
| 8 | + * increment, and lose a write — the observer then fired at unpredictable |
| 9 | + * intervals. The fix serializes the read-modify-write with an atomic mkdir |
| 10 | + * lock. |
| 11 | + * |
| 12 | + * These tests drive the real observe.sh (reusing the stub harness from |
| 13 | + * observer-memory.test.js) and assert the lock's invariant: with the reset |
| 14 | + * threshold set high enough that no reset fires, the final counter must equal |
| 15 | + * the number of invocations — i.e. no increment is ever lost, even under heavy |
| 16 | + * concurrency. |
| 17 | + * |
| 18 | + * Run with: node tests/hooks/observe-signal-counter-race.test.js |
| 19 | + */ |
| 20 | + |
| 21 | +const assert = require('assert'); |
| 22 | +const path = require('path'); |
| 23 | +const fs = require('fs'); |
| 24 | +const os = require('os'); |
| 25 | +const { spawn, spawnSync } = require('child_process'); |
| 26 | + |
| 27 | +let passed = 0; |
| 28 | +let failed = 0; |
| 29 | + |
| 30 | +function test(name, fn) { |
| 31 | + try { |
| 32 | + fn(); |
| 33 | + console.log(` ✓ ${name}`); |
| 34 | + passed++; |
| 35 | + } catch (err) { |
| 36 | + console.log(` ✗ ${name}`); |
| 37 | + console.log(` Error: ${err.message}`); |
| 38 | + failed++; |
| 39 | + } |
| 40 | +} |
| 41 | + |
| 42 | +async function asyncTest(name, fn) { |
| 43 | + try { |
| 44 | + await fn(); |
| 45 | + console.log(` ✓ ${name}`); |
| 46 | + passed++; |
| 47 | + } catch (err) { |
| 48 | + console.log(` ✗ ${name}`); |
| 49 | + console.log(` Error: ${err.message}`); |
| 50 | + failed++; |
| 51 | + } |
| 52 | +} |
| 53 | + |
| 54 | +function createTempDir() { |
| 55 | + return fs.mkdtempSync(path.join(os.tmpdir(), 'ecc-signal-race-')); |
| 56 | +} |
| 57 | + |
| 58 | +function cleanupDir(dir) { |
| 59 | + try { |
| 60 | + fs.rmSync(dir, { recursive: true, force: true }); |
| 61 | + } catch { |
| 62 | + // ignore cleanup errors |
| 63 | + } |
| 64 | +} |
| 65 | + |
| 66 | +const repoRoot = path.resolve(__dirname, '..', '..'); |
| 67 | +const observeShPath = path.join(repoRoot, 'skills', 'continuous-learning-v2', 'hooks', 'observe.sh'); |
| 68 | + |
| 69 | +const isWindows = process.platform === 'win32'; |
| 70 | +const hasPython = !isWindows && spawnSync('python3', ['--version']).status === 0; |
| 71 | +// When the runner has flock the lock is exact (blocking, kernel auto-release); |
| 72 | +// without it observe.sh uses a best-effort mkdir spin that may drop at most one |
| 73 | +// increment under pathological contention. |
| 74 | +const hasFlock = !isWindows && spawnSync('bash', ['-c', 'command -v flock']).status === 0; |
| 75 | + |
| 76 | +// Build a self-contained observe.sh sandbox (stub detect-project.sh + |
| 77 | +// homunculus-dir.sh, SKILL_ROOT patched to the sandbox) and return its paths. |
| 78 | +function buildSandbox() { |
| 79 | + const testDir = createTempDir(); |
| 80 | + const projectDir = path.join(testDir, 'project'); |
| 81 | + fs.mkdirSync(projectDir, { recursive: true }); |
| 82 | + |
| 83 | + const skillRoot = path.join(testDir, 'skill'); |
| 84 | + const scriptsDir = path.join(skillRoot, 'scripts'); |
| 85 | + const scriptsLibDir = path.join(scriptsDir, 'lib'); |
| 86 | + const hooksDir = path.join(skillRoot, 'hooks'); |
| 87 | + fs.mkdirSync(scriptsDir, { recursive: true }); |
| 88 | + fs.mkdirSync(scriptsLibDir, { recursive: true }); |
| 89 | + fs.mkdirSync(hooksDir, { recursive: true }); |
| 90 | + |
| 91 | + fs.writeFileSync( |
| 92 | + path.join(scriptsDir, 'detect-project.sh'), |
| 93 | + [ |
| 94 | + '#!/bin/bash', |
| 95 | + 'PROJECT_ID="test-project"', |
| 96 | + 'PROJECT_NAME="test-project"', |
| 97 | + `PROJECT_ROOT="${projectDir}"`, |
| 98 | + `PROJECT_DIR="${projectDir}"`, |
| 99 | + 'CLV2_PYTHON_CMD="python3"', |
| 100 | + '' |
| 101 | + ].join('\n') |
| 102 | + ); |
| 103 | + fs.writeFileSync( |
| 104 | + path.join(scriptsLibDir, 'homunculus-dir.sh'), |
| 105 | + [ |
| 106 | + '#!/bin/bash', |
| 107 | + '_ecc_resolve_homunculus_dir() { printf "%s\\n" "$HOME/.local/share/ecc-homunculus"; }', |
| 108 | + '' |
| 109 | + ].join('\n') |
| 110 | + ); |
| 111 | + |
| 112 | + let observeContent = fs.readFileSync(observeShPath, 'utf8'); |
| 113 | + const skillRootMarker = 'SKILL_ROOT="$(cd "$SCRIPT_DIR/.." && pwd)"'; |
| 114 | + // Fail fast if observe.sh's SKILL_ROOT definition drifts; otherwise the |
| 115 | + // no-op replace would leave the sandbox pointing at the real skill tree and |
| 116 | + // the test could pass spuriously. |
| 117 | + assert.ok( |
| 118 | + observeContent.includes(skillRootMarker), |
| 119 | + 'observe.sh SKILL_ROOT definition changed; update the sandbox rewrite' |
| 120 | + ); |
| 121 | + observeContent = observeContent.replace( |
| 122 | + skillRootMarker, |
| 123 | + `SKILL_ROOT="${skillRoot}"` |
| 124 | + ); |
| 125 | + const testObserve = path.join(hooksDir, 'observe.sh'); |
| 126 | + fs.writeFileSync(testObserve, observeContent, { mode: 0o755 }); |
| 127 | + |
| 128 | + return { testDir, projectDir, testObserve }; |
| 129 | +} |
| 130 | + |
| 131 | +// Run observe.sh once against the sandbox. Resolves when the process exits. |
| 132 | +function runObserve(testObserve, projectDir) { |
| 133 | + const input = JSON.stringify({ |
| 134 | + tool_name: 'Read', |
| 135 | + tool_input: { file_path: '/tmp/test.txt' }, |
| 136 | + session_id: 'test-session', |
| 137 | + cwd: projectDir |
| 138 | + }); |
| 139 | + return new Promise((resolve, reject) => { |
| 140 | + const child = spawn('bash', [testObserve, 'post'], { |
| 141 | + env: { |
| 142 | + ...process.env, |
| 143 | + HOME: projectDir, |
| 144 | + CLAUDE_CODE_ENTRYPOINT: 'cli', |
| 145 | + ECC_HOOK_PROFILE: 'standard', |
| 146 | + ECC_SKIP_OBSERVE: '0', |
| 147 | + CLAUDE_PROJECT_DIR: projectDir, |
| 148 | + // Reset threshold far above the invocation count, so no reset fires and |
| 149 | + // the final counter equals the number of invocations. |
| 150 | + ECC_OBSERVER_SIGNAL_EVERY_N: '100000' |
| 151 | + }, |
| 152 | + stdio: ['pipe', 'ignore', 'pipe'] |
| 153 | + }); |
| 154 | + let stderr = ''; |
| 155 | + // Fail the test on a hung hook rather than waiting forever. |
| 156 | + const timer = setTimeout(() => { |
| 157 | + child.kill('SIGKILL'); |
| 158 | + reject(new Error('observe.sh timed out')); |
| 159 | + }, 20000); |
| 160 | + child.stderr.on('data', (chunk) => { stderr += chunk; }); |
| 161 | + // A broken observe.sh must fail the test, not be silently swallowed. |
| 162 | + child.on('close', (code, signal) => { |
| 163 | + clearTimeout(timer); |
| 164 | + if (code === 0 && signal === null) { |
| 165 | + resolve(); |
| 166 | + } else { |
| 167 | + reject(new Error(`observe.sh failed code=${code} signal=${signal}: ${stderr.trim()}`)); |
| 168 | + } |
| 169 | + }); |
| 170 | + child.on('error', (err) => { |
| 171 | + clearTimeout(timer); |
| 172 | + reject(err); |
| 173 | + }); |
| 174 | + child.stdin.end(input); |
| 175 | + }); |
| 176 | +} |
| 177 | + |
| 178 | +function readCounter(projectDir) { |
| 179 | + const counterFile = path.join(projectDir, '.observer-signal-counter'); |
| 180 | + if (!fs.existsSync(counterFile)) { |
| 181 | + return null; |
| 182 | + } |
| 183 | + return parseInt(fs.readFileSync(counterFile, 'utf8').trim(), 10); |
| 184 | +} |
| 185 | + |
| 186 | +console.log('\n=== observe.sh signal-counter race regression (#2296) ===\n'); |
| 187 | + |
| 188 | +test('observe.sh uses a lock around the throttle-counter update', () => { |
| 189 | + const content = fs.readFileSync(observeShPath, 'utf8'); |
| 190 | + assert.ok( |
| 191 | + content.includes('SIGNAL_COUNTER_LOCK'), |
| 192 | + 'observe.sh should define a lock for the signal counter' |
| 193 | + ); |
| 194 | + assert.ok( |
| 195 | + /flock 8\b/.test(content) || /mkdir "\$SIGNAL_COUNTER_LOCK"/.test(content), |
| 196 | + 'observe.sh should acquire the counter lock via flock or an atomic mkdir' |
| 197 | + ); |
| 198 | +}); |
| 199 | + |
| 200 | +test('observe.sh guards against a corrupt (non-integer) counter file', () => { |
| 201 | + const content = fs.readFileSync(observeShPath, 'utf8'); |
| 202 | + assert.ok( |
| 203 | + /''\|\*\[!0-9\]\*\) counter=0/.test(content), |
| 204 | + 'observe.sh should reset a non-integer counter to 0 before incrementing' |
| 205 | + ); |
| 206 | +}); |
| 207 | + |
| 208 | +async function runSequential() { |
| 209 | + const { testDir, projectDir, testObserve } = buildSandbox(); |
| 210 | + try { |
| 211 | + const N = 5; |
| 212 | + for (let i = 0; i < N; i++) { |
| 213 | + await runObserve(testObserve, projectDir); |
| 214 | + } |
| 215 | + const counter = readCounter(projectDir); |
| 216 | + assert.notStrictEqual(counter, null, 'counter file should exist after runs'); |
| 217 | + assert.strictEqual(counter, N, `sequential counter should be ${N}, got ${counter}`); |
| 218 | + } finally { |
| 219 | + cleanupDir(testDir); |
| 220 | + } |
| 221 | +} |
| 222 | + |
| 223 | +async function runConcurrent() { |
| 224 | + const { testDir, projectDir, testObserve } = buildSandbox(); |
| 225 | + try { |
| 226 | + const K = 20; |
| 227 | + // Spawn all K before awaiting any, so they genuinely contend on the counter. |
| 228 | + const runs = []; |
| 229 | + for (let i = 0; i < K; i++) { |
| 230 | + runs.push(runObserve(testObserve, projectDir)); |
| 231 | + } |
| 232 | + await Promise.all(runs); |
| 233 | + const counter = readCounter(projectDir); |
| 234 | + assert.notStrictEqual(counter, null, 'counter file should exist after concurrent runs'); |
| 235 | + if (hasFlock) { |
| 236 | + // flock serializes every invocation, so no increment is ever lost. The |
| 237 | + // pre-fix unlocked code drops increments under this same contention. |
| 238 | + assert.strictEqual( |
| 239 | + counter, |
| 240 | + K, |
| 241 | + `with flock the counter must be exactly ${K}, got ${counter}` |
| 242 | + ); |
| 243 | + } else { |
| 244 | + // mkdir fallback is best-effort: it may drop at most one increment if its |
| 245 | + // bounded spin is exhausted, but never the multi-increment loss the |
| 246 | + // unlocked code exhibited. |
| 247 | + assert.ok( |
| 248 | + counter >= K - 1, |
| 249 | + `mkdir fallback should keep the counter >= ${K - 1}, got ${counter}` |
| 250 | + ); |
| 251 | + } |
| 252 | + } finally { |
| 253 | + cleanupDir(testDir); |
| 254 | + } |
| 255 | +} |
| 256 | + |
| 257 | +(async () => { |
| 258 | + if (!isWindows && hasPython) { |
| 259 | + await asyncTest('sequential invocations increment the counter exactly once each', runSequential); |
| 260 | + await asyncTest('concurrent invocations never lose a counter increment', runConcurrent); |
| 261 | + } else { |
| 262 | + console.log(' - skipping shell-execution tests (requires non-Windows + python3)'); |
| 263 | + } |
| 264 | + |
| 265 | + console.log('\n=== Test Results ==='); |
| 266 | + console.log(`Passed: ${passed}`); |
| 267 | + console.log(`Failed: ${failed}`); |
| 268 | + console.log(`Total: ${passed + failed}`); |
| 269 | + |
| 270 | + process.exit(failed > 0 ? 1 : 0); |
| 271 | +})(); |
0 commit comments