mirror of
https://github.com/obra/superpowers.git
synced 2026-04-23 09:59:05 +08:00
Consolidate debugging techniques into systematic-debugging skill
Move condition-based-waiting, defense-in-depth, and root-cause-tracing into systematic-debugging as progressive disclosure supporting files. These techniques are now available as reference material within the systematic-debugging skill directory, reducing skill count while keeping content accessible when needed. Note: Claude Code's SLASH_COMMAND_TOOL_CHAR_BUDGET env variable silently limits skill discovery, which drove this consolidation to ensure core skills remain visible.
This commit is contained in:
@@ -111,7 +111,7 @@ You MUST complete each phase before proceeding to the next.
|
||||
|
||||
**WHEN error is deep in call stack:**
|
||||
|
||||
**REQUIRED SUB-SKILL:** Use superpowers:root-cause-tracing for backward tracing technique
|
||||
See `root-cause-tracing.md` in this directory for the complete backward tracing technique.
|
||||
|
||||
**Quick version:**
|
||||
- Where does bad value originate?
|
||||
@@ -176,7 +176,7 @@ You MUST complete each phase before proceeding to the next.
|
||||
- Automated test if possible
|
||||
- One-off test script if no framework
|
||||
- MUST have before fixing
|
||||
- **REQUIRED SUB-SKILL:** Use superpowers:test-driven-development for writing proper failing tests
|
||||
- Use the `superpowers:test-driven-development` skill for writing proper failing tests
|
||||
|
||||
2. **Implement Single Fix**
|
||||
- Address the root cause identified
|
||||
@@ -275,16 +275,17 @@ If systematic investigation reveals issue is truly environmental, timing-depende
|
||||
|
||||
**But:** 95% of "no root cause" cases are incomplete investigation.
|
||||
|
||||
## Integration with Other Skills
|
||||
## Supporting Techniques
|
||||
|
||||
**This skill requires using:**
|
||||
- **root-cause-tracing** - REQUIRED when error is deep in call stack (see Phase 1, Step 5)
|
||||
- **test-driven-development** - REQUIRED for creating failing test case (see Phase 4, Step 1)
|
||||
These techniques are part of systematic debugging and available in this directory:
|
||||
|
||||
**Complementary skills:**
|
||||
- **defense-in-depth** - Add validation at multiple layers after finding root cause
|
||||
- **condition-based-waiting** - Replace arbitrary timeouts identified in Phase 2
|
||||
- **verification-before-completion** - Verify fix worked before claiming success
|
||||
- **`root-cause-tracing.md`** - Trace bugs backward through call stack to find original trigger
|
||||
- **`defense-in-depth.md`** - Add validation at multiple layers after finding root cause
|
||||
- **`condition-based-waiting.md`** - Replace arbitrary timeouts with condition polling
|
||||
|
||||
**Related skills:**
|
||||
- **superpowers:test-driven-development** - For creating failing test case (Phase 4, Step 1)
|
||||
- **superpowers:verification-before-completion** - Verify fix worked before claiming success
|
||||
|
||||
## Real-World Impact
|
||||
|
||||
|
||||
158
skills/systematic-debugging/condition-based-waiting-example.ts
Normal file
158
skills/systematic-debugging/condition-based-waiting-example.ts
Normal file
@@ -0,0 +1,158 @@
|
||||
// Complete implementation of condition-based waiting utilities
|
||||
// From: Lace test infrastructure improvements (2025-10-03)
|
||||
// Context: Fixed 15 flaky tests by replacing arbitrary timeouts
|
||||
|
||||
import type { ThreadManager } from '~/threads/thread-manager';
|
||||
import type { LaceEvent, LaceEventType } from '~/threads/types';
|
||||
|
||||
/**
|
||||
* Wait for a specific event type to appear in thread
|
||||
*
|
||||
* @param threadManager - The thread manager to query
|
||||
* @param threadId - Thread to check for events
|
||||
* @param eventType - Type of event to wait for
|
||||
* @param timeoutMs - Maximum time to wait (default 5000ms)
|
||||
* @returns Promise resolving to the first matching event
|
||||
*
|
||||
* Example:
|
||||
* await waitForEvent(threadManager, agentThreadId, 'TOOL_RESULT');
|
||||
*/
|
||||
export function waitForEvent(
|
||||
threadManager: ThreadManager,
|
||||
threadId: string,
|
||||
eventType: LaceEventType,
|
||||
timeoutMs = 5000
|
||||
): Promise<LaceEvent> {
|
||||
return new Promise((resolve, reject) => {
|
||||
const startTime = Date.now();
|
||||
|
||||
const check = () => {
|
||||
const events = threadManager.getEvents(threadId);
|
||||
const event = events.find((e) => e.type === eventType);
|
||||
|
||||
if (event) {
|
||||
resolve(event);
|
||||
} else if (Date.now() - startTime > timeoutMs) {
|
||||
reject(new Error(`Timeout waiting for ${eventType} event after ${timeoutMs}ms`));
|
||||
} else {
|
||||
setTimeout(check, 10); // Poll every 10ms for efficiency
|
||||
}
|
||||
};
|
||||
|
||||
check();
|
||||
});
|
||||
}
|
||||
|
||||
/**
|
||||
* Wait for a specific number of events of a given type
|
||||
*
|
||||
* @param threadManager - The thread manager to query
|
||||
* @param threadId - Thread to check for events
|
||||
* @param eventType - Type of event to wait for
|
||||
* @param count - Number of events to wait for
|
||||
* @param timeoutMs - Maximum time to wait (default 5000ms)
|
||||
* @returns Promise resolving to all matching events once count is reached
|
||||
*
|
||||
* Example:
|
||||
* // Wait for 2 AGENT_MESSAGE events (initial response + continuation)
|
||||
* await waitForEventCount(threadManager, agentThreadId, 'AGENT_MESSAGE', 2);
|
||||
*/
|
||||
export function waitForEventCount(
|
||||
threadManager: ThreadManager,
|
||||
threadId: string,
|
||||
eventType: LaceEventType,
|
||||
count: number,
|
||||
timeoutMs = 5000
|
||||
): Promise<LaceEvent[]> {
|
||||
return new Promise((resolve, reject) => {
|
||||
const startTime = Date.now();
|
||||
|
||||
const check = () => {
|
||||
const events = threadManager.getEvents(threadId);
|
||||
const matchingEvents = events.filter((e) => e.type === eventType);
|
||||
|
||||
if (matchingEvents.length >= count) {
|
||||
resolve(matchingEvents);
|
||||
} else if (Date.now() - startTime > timeoutMs) {
|
||||
reject(
|
||||
new Error(
|
||||
`Timeout waiting for ${count} ${eventType} events after ${timeoutMs}ms (got ${matchingEvents.length})`
|
||||
)
|
||||
);
|
||||
} else {
|
||||
setTimeout(check, 10);
|
||||
}
|
||||
};
|
||||
|
||||
check();
|
||||
});
|
||||
}
|
||||
|
||||
/**
|
||||
* Wait for an event matching a custom predicate
|
||||
* Useful when you need to check event data, not just type
|
||||
*
|
||||
* @param threadManager - The thread manager to query
|
||||
* @param threadId - Thread to check for events
|
||||
* @param predicate - Function that returns true when event matches
|
||||
* @param description - Human-readable description for error messages
|
||||
* @param timeoutMs - Maximum time to wait (default 5000ms)
|
||||
* @returns Promise resolving to the first matching event
|
||||
*
|
||||
* Example:
|
||||
* // Wait for TOOL_RESULT with specific ID
|
||||
* await waitForEventMatch(
|
||||
* threadManager,
|
||||
* agentThreadId,
|
||||
* (e) => e.type === 'TOOL_RESULT' && e.data.id === 'call_123',
|
||||
* 'TOOL_RESULT with id=call_123'
|
||||
* );
|
||||
*/
|
||||
export function waitForEventMatch(
|
||||
threadManager: ThreadManager,
|
||||
threadId: string,
|
||||
predicate: (event: LaceEvent) => boolean,
|
||||
description: string,
|
||||
timeoutMs = 5000
|
||||
): Promise<LaceEvent> {
|
||||
return new Promise((resolve, reject) => {
|
||||
const startTime = Date.now();
|
||||
|
||||
const check = () => {
|
||||
const events = threadManager.getEvents(threadId);
|
||||
const event = events.find(predicate);
|
||||
|
||||
if (event) {
|
||||
resolve(event);
|
||||
} else if (Date.now() - startTime > timeoutMs) {
|
||||
reject(new Error(`Timeout waiting for ${description} after ${timeoutMs}ms`));
|
||||
} else {
|
||||
setTimeout(check, 10);
|
||||
}
|
||||
};
|
||||
|
||||
check();
|
||||
});
|
||||
}
|
||||
|
||||
// Usage example from actual debugging session:
|
||||
//
|
||||
// BEFORE (flaky):
|
||||
// ---------------
|
||||
// const messagePromise = agent.sendMessage('Execute tools');
|
||||
// await new Promise(r => setTimeout(r, 300)); // Hope tools start in 300ms
|
||||
// agent.abort();
|
||||
// await messagePromise;
|
||||
// await new Promise(r => setTimeout(r, 50)); // Hope results arrive in 50ms
|
||||
// expect(toolResults.length).toBe(2); // Fails randomly
|
||||
//
|
||||
// AFTER (reliable):
|
||||
// ----------------
|
||||
// const messagePromise = agent.sendMessage('Execute tools');
|
||||
// await waitForEventCount(threadManager, threadId, 'TOOL_CALL', 2); // Wait for tools to start
|
||||
// agent.abort();
|
||||
// await messagePromise;
|
||||
// await waitForEventCount(threadManager, threadId, 'TOOL_RESULT', 2); // Wait for results
|
||||
// expect(toolResults.length).toBe(2); // Always succeeds
|
||||
//
|
||||
// Result: 60% pass rate → 100%, 40% faster execution
|
||||
115
skills/systematic-debugging/condition-based-waiting.md
Normal file
115
skills/systematic-debugging/condition-based-waiting.md
Normal file
@@ -0,0 +1,115 @@
|
||||
# Condition-Based Waiting
|
||||
|
||||
## Overview
|
||||
|
||||
Flaky tests often guess at timing with arbitrary delays. This creates race conditions where tests pass on fast machines but fail under load or in CI.
|
||||
|
||||
**Core principle:** Wait for the actual condition you care about, not a guess about how long it takes.
|
||||
|
||||
## When to Use
|
||||
|
||||
```dot
|
||||
digraph when_to_use {
|
||||
"Test uses setTimeout/sleep?" [shape=diamond];
|
||||
"Testing timing behavior?" [shape=diamond];
|
||||
"Document WHY timeout needed" [shape=box];
|
||||
"Use condition-based waiting" [shape=box];
|
||||
|
||||
"Test uses setTimeout/sleep?" -> "Testing timing behavior?" [label="yes"];
|
||||
"Testing timing behavior?" -> "Document WHY timeout needed" [label="yes"];
|
||||
"Testing timing behavior?" -> "Use condition-based waiting" [label="no"];
|
||||
}
|
||||
```
|
||||
|
||||
**Use when:**
|
||||
- Tests have arbitrary delays (`setTimeout`, `sleep`, `time.sleep()`)
|
||||
- Tests are flaky (pass sometimes, fail under load)
|
||||
- Tests timeout when run in parallel
|
||||
- Waiting for async operations to complete
|
||||
|
||||
**Don't use when:**
|
||||
- Testing actual timing behavior (debounce, throttle intervals)
|
||||
- Always document WHY if using arbitrary timeout
|
||||
|
||||
## Core Pattern
|
||||
|
||||
```typescript
|
||||
// ❌ BEFORE: Guessing at timing
|
||||
await new Promise(r => setTimeout(r, 50));
|
||||
const result = getResult();
|
||||
expect(result).toBeDefined();
|
||||
|
||||
// ✅ AFTER: Waiting for condition
|
||||
await waitFor(() => getResult() !== undefined);
|
||||
const result = getResult();
|
||||
expect(result).toBeDefined();
|
||||
```
|
||||
|
||||
## Quick Patterns
|
||||
|
||||
| Scenario | Pattern |
|
||||
|----------|---------|
|
||||
| Wait for event | `waitFor(() => events.find(e => e.type === 'DONE'))` |
|
||||
| Wait for state | `waitFor(() => machine.state === 'ready')` |
|
||||
| Wait for count | `waitFor(() => items.length >= 5)` |
|
||||
| Wait for file | `waitFor(() => fs.existsSync(path))` |
|
||||
| Complex condition | `waitFor(() => obj.ready && obj.value > 10)` |
|
||||
|
||||
## Implementation
|
||||
|
||||
Generic polling function:
|
||||
```typescript
|
||||
async function waitFor<T>(
|
||||
condition: () => T | undefined | null | false,
|
||||
description: string,
|
||||
timeoutMs = 5000
|
||||
): Promise<T> {
|
||||
const startTime = Date.now();
|
||||
|
||||
while (true) {
|
||||
const result = condition();
|
||||
if (result) return result;
|
||||
|
||||
if (Date.now() - startTime > timeoutMs) {
|
||||
throw new Error(`Timeout waiting for ${description} after ${timeoutMs}ms`);
|
||||
}
|
||||
|
||||
await new Promise(r => setTimeout(r, 10)); // Poll every 10ms
|
||||
}
|
||||
}
|
||||
```
|
||||
|
||||
See `condition-based-waiting-example.ts` in this directory for complete implementation with domain-specific helpers (`waitForEvent`, `waitForEventCount`, `waitForEventMatch`) from actual debugging session.
|
||||
|
||||
## Common Mistakes
|
||||
|
||||
**❌ Polling too fast:** `setTimeout(check, 1)` - wastes CPU
|
||||
**✅ Fix:** Poll every 10ms
|
||||
|
||||
**❌ No timeout:** Loop forever if condition never met
|
||||
**✅ Fix:** Always include timeout with clear error
|
||||
|
||||
**❌ Stale data:** Cache state before loop
|
||||
**✅ Fix:** Call getter inside loop for fresh data
|
||||
|
||||
## When Arbitrary Timeout IS Correct
|
||||
|
||||
```typescript
|
||||
// Tool ticks every 100ms - need 2 ticks to verify partial output
|
||||
await waitForEvent(manager, 'TOOL_STARTED'); // First: wait for condition
|
||||
await new Promise(r => setTimeout(r, 200)); // Then: wait for timed behavior
|
||||
// 200ms = 2 ticks at 100ms intervals - documented and justified
|
||||
```
|
||||
|
||||
**Requirements:**
|
||||
1. First wait for triggering condition
|
||||
2. Based on known timing (not guessing)
|
||||
3. Comment explaining WHY
|
||||
|
||||
## Real-World Impact
|
||||
|
||||
From debugging session (2025-10-03):
|
||||
- Fixed 15 flaky tests across 3 files
|
||||
- Pass rate: 60% → 100%
|
||||
- Execution time: 40% faster
|
||||
- No more race conditions
|
||||
122
skills/systematic-debugging/defense-in-depth.md
Normal file
122
skills/systematic-debugging/defense-in-depth.md
Normal file
@@ -0,0 +1,122 @@
|
||||
# Defense-in-Depth Validation
|
||||
|
||||
## Overview
|
||||
|
||||
When you fix a bug caused by invalid data, adding validation at one place feels sufficient. But that single check can be bypassed by different code paths, refactoring, or mocks.
|
||||
|
||||
**Core principle:** Validate at EVERY layer data passes through. Make the bug structurally impossible.
|
||||
|
||||
## Why Multiple Layers
|
||||
|
||||
Single validation: "We fixed the bug"
|
||||
Multiple layers: "We made the bug impossible"
|
||||
|
||||
Different layers catch different cases:
|
||||
- Entry validation catches most bugs
|
||||
- Business logic catches edge cases
|
||||
- Environment guards prevent context-specific dangers
|
||||
- Debug logging helps when other layers fail
|
||||
|
||||
## The Four Layers
|
||||
|
||||
### Layer 1: Entry Point Validation
|
||||
**Purpose:** Reject obviously invalid input at API boundary
|
||||
|
||||
```typescript
|
||||
function createProject(name: string, workingDirectory: string) {
|
||||
if (!workingDirectory || workingDirectory.trim() === '') {
|
||||
throw new Error('workingDirectory cannot be empty');
|
||||
}
|
||||
if (!existsSync(workingDirectory)) {
|
||||
throw new Error(`workingDirectory does not exist: ${workingDirectory}`);
|
||||
}
|
||||
if (!statSync(workingDirectory).isDirectory()) {
|
||||
throw new Error(`workingDirectory is not a directory: ${workingDirectory}`);
|
||||
}
|
||||
// ... proceed
|
||||
}
|
||||
```
|
||||
|
||||
### Layer 2: Business Logic Validation
|
||||
**Purpose:** Ensure data makes sense for this operation
|
||||
|
||||
```typescript
|
||||
function initializeWorkspace(projectDir: string, sessionId: string) {
|
||||
if (!projectDir) {
|
||||
throw new Error('projectDir required for workspace initialization');
|
||||
}
|
||||
// ... proceed
|
||||
}
|
||||
```
|
||||
|
||||
### Layer 3: Environment Guards
|
||||
**Purpose:** Prevent dangerous operations in specific contexts
|
||||
|
||||
```typescript
|
||||
async function gitInit(directory: string) {
|
||||
// In tests, refuse git init outside temp directories
|
||||
if (process.env.NODE_ENV === 'test') {
|
||||
const normalized = normalize(resolve(directory));
|
||||
const tmpDir = normalize(resolve(tmpdir()));
|
||||
|
||||
if (!normalized.startsWith(tmpDir)) {
|
||||
throw new Error(
|
||||
`Refusing git init outside temp dir during tests: ${directory}`
|
||||
);
|
||||
}
|
||||
}
|
||||
// ... proceed
|
||||
}
|
||||
```
|
||||
|
||||
### Layer 4: Debug Instrumentation
|
||||
**Purpose:** Capture context for forensics
|
||||
|
||||
```typescript
|
||||
async function gitInit(directory: string) {
|
||||
const stack = new Error().stack;
|
||||
logger.debug('About to git init', {
|
||||
directory,
|
||||
cwd: process.cwd(),
|
||||
stack,
|
||||
});
|
||||
// ... proceed
|
||||
}
|
||||
```
|
||||
|
||||
## Applying the Pattern
|
||||
|
||||
When you find a bug:
|
||||
|
||||
1. **Trace the data flow** - Where does bad value originate? Where used?
|
||||
2. **Map all checkpoints** - List every point data passes through
|
||||
3. **Add validation at each layer** - Entry, business, environment, debug
|
||||
4. **Test each layer** - Try to bypass layer 1, verify layer 2 catches it
|
||||
|
||||
## Example from Session
|
||||
|
||||
Bug: Empty `projectDir` caused `git init` in source code
|
||||
|
||||
**Data flow:**
|
||||
1. Test setup → empty string
|
||||
2. `Project.create(name, '')`
|
||||
3. `WorkspaceManager.createWorkspace('')`
|
||||
4. `git init` runs in `process.cwd()`
|
||||
|
||||
**Four layers added:**
|
||||
- Layer 1: `Project.create()` validates not empty/exists/writable
|
||||
- Layer 2: `WorkspaceManager` validates projectDir not empty
|
||||
- Layer 3: `WorktreeManager` refuses git init outside tmpdir in tests
|
||||
- Layer 4: Stack trace logging before git init
|
||||
|
||||
**Result:** All 1847 tests passed, bug impossible to reproduce
|
||||
|
||||
## Key Insight
|
||||
|
||||
All four layers were necessary. During testing, each layer caught bugs the others missed:
|
||||
- Different code paths bypassed entry validation
|
||||
- Mocks bypassed business logic checks
|
||||
- Edge cases on different platforms needed environment guards
|
||||
- Debug logging identified structural misuse
|
||||
|
||||
**Don't stop at one validation point.** Add checks at every layer.
|
||||
63
skills/systematic-debugging/find-polluter.sh
Executable file
63
skills/systematic-debugging/find-polluter.sh
Executable file
@@ -0,0 +1,63 @@
|
||||
#!/usr/bin/env bash
|
||||
# Bisection script to find which test creates unwanted files/state
|
||||
# Usage: ./find-polluter.sh <file_or_dir_to_check> <test_pattern>
|
||||
# Example: ./find-polluter.sh '.git' 'src/**/*.test.ts'
|
||||
|
||||
set -e
|
||||
|
||||
if [ $# -ne 2 ]; then
|
||||
echo "Usage: $0 <file_to_check> <test_pattern>"
|
||||
echo "Example: $0 '.git' 'src/**/*.test.ts'"
|
||||
exit 1
|
||||
fi
|
||||
|
||||
POLLUTION_CHECK="$1"
|
||||
TEST_PATTERN="$2"
|
||||
|
||||
echo "🔍 Searching for test that creates: $POLLUTION_CHECK"
|
||||
echo "Test pattern: $TEST_PATTERN"
|
||||
echo ""
|
||||
|
||||
# Get list of test files
|
||||
TEST_FILES=$(find . -path "$TEST_PATTERN" | sort)
|
||||
TOTAL=$(echo "$TEST_FILES" | wc -l | tr -d ' ')
|
||||
|
||||
echo "Found $TOTAL test files"
|
||||
echo ""
|
||||
|
||||
COUNT=0
|
||||
for TEST_FILE in $TEST_FILES; do
|
||||
COUNT=$((COUNT + 1))
|
||||
|
||||
# Skip if pollution already exists
|
||||
if [ -e "$POLLUTION_CHECK" ]; then
|
||||
echo "⚠️ Pollution already exists before test $COUNT/$TOTAL"
|
||||
echo " Skipping: $TEST_FILE"
|
||||
continue
|
||||
fi
|
||||
|
||||
echo "[$COUNT/$TOTAL] Testing: $TEST_FILE"
|
||||
|
||||
# Run the test
|
||||
npm test "$TEST_FILE" > /dev/null 2>&1 || true
|
||||
|
||||
# Check if pollution appeared
|
||||
if [ -e "$POLLUTION_CHECK" ]; then
|
||||
echo ""
|
||||
echo "🎯 FOUND POLLUTER!"
|
||||
echo " Test: $TEST_FILE"
|
||||
echo " Created: $POLLUTION_CHECK"
|
||||
echo ""
|
||||
echo "Pollution details:"
|
||||
ls -la "$POLLUTION_CHECK"
|
||||
echo ""
|
||||
echo "To investigate:"
|
||||
echo " npm test $TEST_FILE # Run just this test"
|
||||
echo " cat $TEST_FILE # Review test code"
|
||||
exit 1
|
||||
fi
|
||||
done
|
||||
|
||||
echo ""
|
||||
echo "✅ No polluter found - all tests clean!"
|
||||
exit 0
|
||||
169
skills/systematic-debugging/root-cause-tracing.md
Normal file
169
skills/systematic-debugging/root-cause-tracing.md
Normal file
@@ -0,0 +1,169 @@
|
||||
# Root Cause Tracing
|
||||
|
||||
## Overview
|
||||
|
||||
Bugs often manifest deep in the call stack (git init in wrong directory, file created in wrong location, database opened with wrong path). Your instinct is to fix where the error appears, but that's treating a symptom.
|
||||
|
||||
**Core principle:** Trace backward through the call chain until you find the original trigger, then fix at the source.
|
||||
|
||||
## When to Use
|
||||
|
||||
```dot
|
||||
digraph when_to_use {
|
||||
"Bug appears deep in stack?" [shape=diamond];
|
||||
"Can trace backwards?" [shape=diamond];
|
||||
"Fix at symptom point" [shape=box];
|
||||
"Trace to original trigger" [shape=box];
|
||||
"BETTER: Also add defense-in-depth" [shape=box];
|
||||
|
||||
"Bug appears deep in stack?" -> "Can trace backwards?" [label="yes"];
|
||||
"Can trace backwards?" -> "Trace to original trigger" [label="yes"];
|
||||
"Can trace backwards?" -> "Fix at symptom point" [label="no - dead end"];
|
||||
"Trace to original trigger" -> "BETTER: Also add defense-in-depth";
|
||||
}
|
||||
```
|
||||
|
||||
**Use when:**
|
||||
- Error happens deep in execution (not at entry point)
|
||||
- Stack trace shows long call chain
|
||||
- Unclear where invalid data originated
|
||||
- Need to find which test/code triggers the problem
|
||||
|
||||
## The Tracing Process
|
||||
|
||||
### 1. Observe the Symptom
|
||||
```
|
||||
Error: git init failed in /Users/jesse/project/packages/core
|
||||
```
|
||||
|
||||
### 2. Find Immediate Cause
|
||||
**What code directly causes this?**
|
||||
```typescript
|
||||
await execFileAsync('git', ['init'], { cwd: projectDir });
|
||||
```
|
||||
|
||||
### 3. Ask: What Called This?
|
||||
```typescript
|
||||
WorktreeManager.createSessionWorktree(projectDir, sessionId)
|
||||
→ called by Session.initializeWorkspace()
|
||||
→ called by Session.create()
|
||||
→ called by test at Project.create()
|
||||
```
|
||||
|
||||
### 4. Keep Tracing Up
|
||||
**What value was passed?**
|
||||
- `projectDir = ''` (empty string!)
|
||||
- Empty string as `cwd` resolves to `process.cwd()`
|
||||
- That's the source code directory!
|
||||
|
||||
### 5. Find Original Trigger
|
||||
**Where did empty string come from?**
|
||||
```typescript
|
||||
const context = setupCoreTest(); // Returns { tempDir: '' }
|
||||
Project.create('name', context.tempDir); // Accessed before beforeEach!
|
||||
```
|
||||
|
||||
## Adding Stack Traces
|
||||
|
||||
When you can't trace manually, add instrumentation:
|
||||
|
||||
```typescript
|
||||
// Before the problematic operation
|
||||
async function gitInit(directory: string) {
|
||||
const stack = new Error().stack;
|
||||
console.error('DEBUG git init:', {
|
||||
directory,
|
||||
cwd: process.cwd(),
|
||||
nodeEnv: process.env.NODE_ENV,
|
||||
stack,
|
||||
});
|
||||
|
||||
await execFileAsync('git', ['init'], { cwd: directory });
|
||||
}
|
||||
```
|
||||
|
||||
**Critical:** Use `console.error()` in tests (not logger - may not show)
|
||||
|
||||
**Run and capture:**
|
||||
```bash
|
||||
npm test 2>&1 | grep 'DEBUG git init'
|
||||
```
|
||||
|
||||
**Analyze stack traces:**
|
||||
- Look for test file names
|
||||
- Find the line number triggering the call
|
||||
- Identify the pattern (same test? same parameter?)
|
||||
|
||||
## Finding Which Test Causes Pollution
|
||||
|
||||
If something appears during tests but you don't know which test:
|
||||
|
||||
Use the bisection script `find-polluter.sh` in this directory:
|
||||
|
||||
```bash
|
||||
./find-polluter.sh '.git' 'src/**/*.test.ts'
|
||||
```
|
||||
|
||||
Runs tests one-by-one, stops at first polluter. See script for usage.
|
||||
|
||||
## Real Example: Empty projectDir
|
||||
|
||||
**Symptom:** `.git` created in `packages/core/` (source code)
|
||||
|
||||
**Trace chain:**
|
||||
1. `git init` runs in `process.cwd()` ← empty cwd parameter
|
||||
2. WorktreeManager called with empty projectDir
|
||||
3. Session.create() passed empty string
|
||||
4. Test accessed `context.tempDir` before beforeEach
|
||||
5. setupCoreTest() returns `{ tempDir: '' }` initially
|
||||
|
||||
**Root cause:** Top-level variable initialization accessing empty value
|
||||
|
||||
**Fix:** Made tempDir a getter that throws if accessed before beforeEach
|
||||
|
||||
**Also added defense-in-depth:**
|
||||
- Layer 1: Project.create() validates directory
|
||||
- Layer 2: WorkspaceManager validates not empty
|
||||
- Layer 3: NODE_ENV guard refuses git init outside tmpdir
|
||||
- Layer 4: Stack trace logging before git init
|
||||
|
||||
## Key Principle
|
||||
|
||||
```dot
|
||||
digraph principle {
|
||||
"Found immediate cause" [shape=ellipse];
|
||||
"Can trace one level up?" [shape=diamond];
|
||||
"Trace backwards" [shape=box];
|
||||
"Is this the source?" [shape=diamond];
|
||||
"Fix at source" [shape=box];
|
||||
"Add validation at each layer" [shape=box];
|
||||
"Bug impossible" [shape=doublecircle];
|
||||
"NEVER fix just the symptom" [shape=octagon, style=filled, fillcolor=red, fontcolor=white];
|
||||
|
||||
"Found immediate cause" -> "Can trace one level up?";
|
||||
"Can trace one level up?" -> "Trace backwards" [label="yes"];
|
||||
"Can trace one level up?" -> "NEVER fix just the symptom" [label="no"];
|
||||
"Trace backwards" -> "Is this the source?";
|
||||
"Is this the source?" -> "Trace backwards" [label="no - keeps going"];
|
||||
"Is this the source?" -> "Fix at source" [label="yes"];
|
||||
"Fix at source" -> "Add validation at each layer";
|
||||
"Add validation at each layer" -> "Bug impossible";
|
||||
}
|
||||
```
|
||||
|
||||
**NEVER fix just where the error appears.** Trace back to find the original trigger.
|
||||
|
||||
## Stack Trace Tips
|
||||
|
||||
**In tests:** Use `console.error()` not logger - logger may be suppressed
|
||||
**Before operation:** Log before the dangerous operation, not after it fails
|
||||
**Include context:** Directory, cwd, environment variables, timestamps
|
||||
**Capture stack:** `new Error().stack` shows complete call chain
|
||||
|
||||
## Real-World Impact
|
||||
|
||||
From debugging session (2025-10-03):
|
||||
- Found root cause through 5-level trace
|
||||
- Fixed at source (getter validation)
|
||||
- Added 4 layers of defense
|
||||
- 1847 tests passed, zero pollution
|
||||
Reference in New Issue
Block a user