hakmem/PHASE7_DEBUG_COMMANDS.md

# Phase 7 Debugging Commands - Action Checklist

**Purpose:** Debug why Phase 7 header-based fast free is NOT working

---

## Quick Status Check

```bash
cd /mnt/workdisk/public_share/hakmem

# Verify Phase 7 flags are enabled
grep -E "HEADER_CLASSIDX|PREWARM_TLS|AGGRESSIVE_INLINE" build.sh

# Should show:
#   HEADER_CLASSIDX=1
#   AGGRESSIVE_INLINE=1
#   PREWARM_TLS=1
```

---

## Investigation 1: Are Headers Being Written?

### Add Debug Logging to Header Write

**File:** `core/tiny_region_id.h:44-58`

**Add this after line 50:**

```c
#if !HAKMEM_BUILD_RELEASE
    fprintf(stderr, "[HEADER_WRITE] ptr=%p cls=%d magic=0x%02x\n",
            user_ptr, class_idx, header);
#endif
```

### Build and Test

```bash
make clean
./build.sh bench_random_mixed_hakmem

# Run with small count to see header writes
./bench_random_mixed_hakmem 10 128 42 2>&1 | grep "HEADER_WRITE"

# Expected output:
# [HEADER_WRITE] ptr=0x7f... cls=4 magic=0xa4
# [HEADER_WRITE] ptr=0x7f... cls=4 magic=0xa4
# ...
```

**If NO output:** Headers are NOT being written! (allocation bug)
**If output present:** Headers ARE being written ✅ (continue to Investigation 2)

---

## Investigation 2: Why Does Header Read Fail?

### Add Debug Logging to Header Read

**File:** `core/tiny_free_fast_v2.inc.h:50-71`

**Add this after line 66 (header read):**

```c
#if !HAKMEM_BUILD_RELEASE
    static int log_count = 0;
    if (log_count < 20) {
        fprintf(stderr, "[HEADER_READ] ptr=%p header_addr=%p header=0x%02x magic_match=%d page_boundary=%d\n",
                ptr, header_addr, header,
                ((header & 0xF0) == TINY_MAGIC) ? 1 : 0,
                (((uintptr_t)ptr & 0xFFF) == 0) ? 1 : 0);
        log_count++;
    }
#endif
```

### Build and Test

```bash
make clean
./build.sh bench_random_mixed_hakmem

./bench_random_mixed_hakmem 100 128 42 2>&1 | grep "HEADER_READ"

# Expected output (if working):
# [HEADER_READ] ptr=0x7f... header_addr=0x7f... header=0xa4 magic_match=1 page_boundary=0

# If magic_match=0: Header validation is failing!
# If page_boundary=1: mincore() might be blocking
```

**Analysis:**
- `header=0xa4` (class 4, magic 0xa) → ✅ Correct
- `header=0xb4` (Pool TLS magic) → ❌ Wrong allocator
- `header=0x00` or random → ❌ Header not written or corrupted
- `magic_match=0` → ❌ Validation logic wrong

---

## Investigation 3: Check Dispatch Priority

### Verify Pool TLS is Not Interfering

**File:** `core/box/hak_free_api.inc.h:81-110`

**Line 102 checks Pool magic BEFORE Tiny magic!**

```c
if ((header & 0xF0) == POOL_MAGIC) {  // 0xb0
    pool_free(ptr);
    goto done;
}
// Tiny check comes AFTER (line 116)
```

**Problem:** If Pool TLS accidentally claims Tiny allocations, they never reach Phase 7 Tiny path!

**Test:** Disable Pool TLS temporarily

```bash
# Edit build.sh - comment out Pool TLS flag
# POOL_TLS_PHASE1=1  ← comment this line

make clean
./build.sh bench_random_mixed_hakmem

HAKMEM_FREE_ROUTE_TRACE=1 ./bench_random_mixed_hakmem 100 128 42 2>&1 | grep "FREE_ROUTE" | sort | uniq -c

# Expected (if Pool TLS was interfering):
# 95 [FREE_ROUTE] header_fast
#  5 [FREE_ROUTE] header_16byte

# If still shows ss_hit: Pool TLS is NOT the problem
```

---

## Investigation 4: Check Return Value of hak_tiny_free_fast_v2

### Add Debug at Call Site

**File:** `core/box/hak_free_api.inc.h:116-122`

**Add this:**

```c
#if !HAKMEM_BUILD_RELEASE
    int result = hak_tiny_free_fast_v2(ptr);
    static int log_count = 0;
    if (log_count < 20) {
        fprintf(stderr, "[FREE_V2] ptr=%p result=%d\n", ptr, result);
        log_count++;
    }
    if (__builtin_expect(result, 1)) {
#else
    if (__builtin_expect(hak_tiny_free_fast_v2(ptr), 1)) {
#endif
```

### Build and Test

```bash
make clean
./build.sh bench_random_mixed_hakmem

./bench_random_mixed_hakmem 100 128 42 2>&1 | grep "FREE_V2"

# Expected output:
# [FREE_V2] ptr=0x7f... result=1  ← Success!
# [FREE_V2] ptr=0x7f... result=0  ← Failure (why?)

# If all result=0: Function ALWAYS fails (logic bug)
# If mixed 0/1: Some allocations work, others don't (routing issue)
```

---

## Investigation 5: Full Trace (Allocation + Free)

### Enable All Debug Logs

```bash
# Temporarily enable all debug in one run
make clean
./build.sh bench_random_mixed_hakmem

./bench_random_mixed_hakmem 10 128 42 2>&1 | tee phase7_debug_full.log

# Analyze log
grep "HEADER_WRITE" phase7_debug_full.log | wc -l  # Count writes
grep "HEADER_READ" phase7_debug_full.log | wc -l   # Count reads
grep "FREE_V2.*result=1" phase7_debug_full.log | wc -l  # Count successes
grep "FREE_V2.*result=0" phase7_debug_full.log | wc -l  # Count failures
grep "FREE_ROUTE.*header_fast" phase7_debug_full.log | wc -l  # Count fast path
grep "FREE_ROUTE.*ss_hit" phase7_debug_full.log | wc -l  # Count slow path
```

**Expected Pattern (if working):**
```
HEADER_WRITE: 10
HEADER_READ: 10
FREE_V2 result=1: 10
header_fast: 10
ss_hit: 0
```

**Actual Pattern (broken):**
```
HEADER_WRITE: 10 (or 0!)
HEADER_READ: 10
FREE_V2 result=0: 10
header_fast: 0
ss_hit: 10
```

---

## Investigation 6: Memory Inspection (Advanced)

### Check Header in Memory Directly

**Add this test:**

```c
// In bench_random_mixed.c (after allocation)
void* p = malloc(128);
if (p) {
    unsigned char* header_addr = (unsigned char*)p - 1;
    fprintf(stderr, "[MEM_CHECK] ptr=%p header_addr=%p header=0x%02x\n",
            p, header_addr, *header_addr);
}
```

**Expected:** `header=0xa4` (class 4, magic 0xa)
**If different:** Header write is broken

---

## Investigation 7: Check Magic Constants

### Verify Magic Definitions

```bash
grep -rn "TINY_MAGIC\|POOL_MAGIC" core/ --include="*.h" | grep "#define"

# Should show:
# core/tiny_region_id.h:  #define TINY_MAGIC 0xa0
# core/pool_tls.h:        #define POOL_MAGIC 0xb0
```

**If TINY_MAGIC != 0xa0:** Wrong magic constant!

---

## Investigation 8: Check Class Index Calculation

### Verify Class Mapping

```c
// Add to header write
fprintf(stderr, "[CLASS_CHECK] size=%zu → class=%d (expected=%d)\n",
        /* original size */, class_idx, /* manual calculation */);

// For 128B: class should be 4 (g_tiny_class_sizes[4] = 128)
```

---

## Decision Tree

```
START
  ↓
Are HEADER_WRITE logs present?
  ├─ NO → Headers NOT written (allocation bug)
  │       → Check HAK_RET_ALLOC macro
  │       → Check tiny_region_id_write_header() calls
  │
  └─ YES → Headers ARE written ✅
        ↓
    Are HEADER_READ logs present?
      ├─ NO → Headers not read (impossible, must be present)
      │
      └─ YES → Headers ARE read ✅
            ↓
        Is magic_match=1?
          ├─ NO → Validation failing
          │       → Check TINY_MAGIC constant (should be 0xa0)
          │       → Check validation logic ((header & 0xF0) == TINY_MAGIC)
          │
          └─ YES → Validation passes ✅
                ↓
            Is FREE_V2 result=1?
              ├─ NO → Function returns failure
              │       → Check class_idx extraction
              │       → Check TLS push logic
              │       → Check return value
              │
              └─ YES → Function succeeds ✅
                    ↓
                Is FREE_ROUTE showing header_fast?
                  ├─ NO → Dispatch priority wrong
                  │       → Pool TLS checked before Tiny?
                  │       → goto done not executed?
                  │
                  └─ YES → **PHASE 7 WORKING!** 🎉
```

---

## Expected Outcomes

### Scenario 1: Headers Not Written

**Symptom:** No `HEADER_WRITE` logs
**Cause:** `tiny_region_id_write_header()` not called
**Fix:** Check `HAK_RET_ALLOC` macro expansion

---

### Scenario 2: Magic Validation Fails

**Symptom:** `magic_match=0` in logs
**Cause:** Wrong magic constant or validation logic
**Fix:** Verify TINY_MAGIC=0xa0, check `(header & 0xF0) == 0xa0`

---

### Scenario 3: Pool TLS Interference

**Symptom:** Disabling Pool TLS fixes it
**Cause:** Pool TLS claims Tiny allocations
**Fix:** Check dispatch priority, ensure Tiny checked first

---

### Scenario 4: Class Index Corruption

**Symptom:** Class index doesn't match size
**Cause:** Wrong class calculation or header corruption
**Fix:** Verify `hak_tiny_size_to_class()` logic

---

## Quick Fix Testing

Once root cause found, test fix:

```bash
# 1. Apply fix
# 2. Rebuild
make clean
./build.sh bench_random_mixed_hakmem

# 3. Verify routing (should show header_fast now!)
HAKMEM_FREE_ROUTE_TRACE=1 ./bench_random_mixed_hakmem 100 128 42 2>&1 | \
    grep "FREE_ROUTE" | sort | uniq -c

# Expected (success):
#  95 [FREE_ROUTE] header_fast
#   5 [FREE_ROUTE] header_16byte

# 4. Benchmark (should show 4-8x improvement!)
for i in 1 2 3; do
    ./bench_random_mixed_hakmem 100000 128 42 2>/dev/null | grep "Throughput"
done

# Expected (if header fast path works):
# Throughput = 18000000+ operations per second  (was 4.5M, now 18M+)
```

---

## Success Criteria

**Phase 7 Header Fast Free is WORKING when:**

1. ✅ `HEADER_WRITE` logs show magic 0xa4 (class 4)
2. ✅ `HEADER_READ` logs show magic_match=1
3. ✅ `FREE_V2` logs show result=1
4. ✅ `FREE_ROUTE` shows 90%+ header_fast (not ss_hit!)
5. ✅ Benchmark shows 15-20M ops/s (4x improvement)

---

**Good luck debugging!** 🔍🐛

If you find the issue, document it in:
`PHASE7_HEADER_FREE_FIX.md`