Implementation:
Ultra-lightweight CPU cycle profiling using RDTSC instruction (~10 cycles overhead).
Changes:
1. Added rdtsc() inline function for x86_64 CPU cycle counter
2. Instrumented tiny_fast_alloc(), tiny_fast_free(), tiny_fast_refill()
3. Track malloc, free, refill, and migration cycles separately
4. Profile output via HAKMEM_TINY_PROFILE=1 environment variable
5. Renamed variables to avoid conflict with core/hakmem.c globals
Files modified:
- core/tiny_fastcache.h: rdtsc(), profile helpers, extern declarations
- core/tiny_fastcache.c: counter definitions, print_profile() output
Usage:
```bash
HAKMEM_TINY_PROFILE=1 ./larson_hakmem 2 8 128 1024 1 12345 4
```
Results (Larson 4 threads, 1.637M ops/s):
```
[MALLOC] count=20,480, avg_cycles=2,476
[REFILL] count=1,285, avg_cycles=38,412 ← 15.5x slower!
[FREE] (no data - not called via fast path)
```
Critical discoveries:
1. **REFILL is the bottleneck:**
- Average 38,412 cycles per refill (15.5x slower than malloc)
- Refill accounts for: 1,285 × 38,412 = 49.3M cycles
- Despite Phase 3 batch optimization, still extremely slow
- Calling hak_tiny_alloc() 16 times has massive overhead
2. **MALLOC is 24x slower than expected:**
- Average 2,476 cycles (expected ~100 cycles for tcache)
- Even cache hits are slow
- Profiling overhead is only ~10 cycles, so real cost is ~2,466 cycles
- Something fundamentally wrong with fast path
3. **Only 2.5% of allocations use fast path:**
- Total operations: 1.637M × 2s = 3.27M ops
- Tiny fast alloc: 20,480 × 4 threads = 81,920 ops
- Coverage: 81,920 / 3,270,000 = **2.5%**
- **97.5% of allocations bypass tiny_fast_alloc entirely!**
4. **FREE is not instrumented:**
- No free() calls captured by profiling
- hakmem.c's free() likely takes different path
- Not calling tiny_fast_free() at all
Root cause analysis:
The 4x performance gap (vs system malloc) is NOT due to:
- Entry point overhead (Phase 1) ❌
- Dual free lists (Phase 2) ❌
- Batch refill efficiency (Phase 3) ❌
The REAL problems:
1. **Tiny fast path is barely used** (2.5% coverage)
2. **Refill is catastrophically slow** (38K cycles)
3. **Even cache hits are 24x too slow** (2.5K cycles)
4. **Free path is completely bypassed**
Why system malloc is 4x faster:
- System tcache has ~100 cycle malloc
- System tcache has ~90% hit rate (vs our 2.5% usage)
- System malloc/free are symmetric (we only optimize malloc)
Next steps:
1. Investigate why 97.5% bypass tiny_fast_alloc
2. Profile the slow path (hak_alloc_at) that handles 97.5%
3. Understand why even cache hits take 2,476 cycles
4. Instrument free() path to see where frees go
5. May need to optimize slow path instead of fast path
This profiling reveals we've been optimizing the wrong thing.
The "fast path" is neither fast (2.5K cycles) nor used (2.5%).
