# 5.6 The two phases of inference and prefix caching

This code answers two questions. First, where does a single request spend its time: are reading the input (prefill) and generating the output token by token (decode) the same kind of work? Second, is prefix caching actually taking effect with the way you assemble prompts: over the same long context, how much difference is there between appending only at the end on each turn (append-only) and inserting a current timestamp at the start on each turn (prepend-timestamp)?

Two scripts run the same three experiments:

- `api_timing.py`: Calls AI Builder Space using streaming responses to measure Time to First Token (TTFT). What happens inside the server has to be inferred from latency.
- `local_cache.py`: Calls a `llama-server` instance running on your own machine. The server reports directly how many input tokens were recomputed (`prompt_n`), how many cached tokens were reused (`cache_n`), and how many milliseconds prefill and decode each took, giving you the clearest view of the mechanics.

## What you need

- `api_timing.py`: Uses the cloud API only, so any computer works.
- `local_cache.py`: An Apple Silicon Mac, an NVIDIA GPU (with a CUDA build of `llama.cpp`), or CPU-only (much slower). The model is a 4-bit GGUF quantization of `Qwen3.5-2B` (~1.2 GB), so 8 GB of RAM is enough to load it. Experiment 3 uses a context of roughly 50,000 tokens, so leave about 2 GB of extra VRAM or system memory.

## Setup and running

Cloud API version:

```bash
cd 5_6_prefill_cache
uv venv && source .venv/bin/activate      # Without uv: python3 -m venv .venv
uv pip install -r requirements.txt
export AI_BUILDER_TOKEN=sk_your_key
python api_timing.py                      # Default: deepseek, 3 experiments, ~3 min, ~$0.40
python api_timing.py --model grok-4-fast --only cache
```

The model must support streaming: `deepseek` and `grok-4-fast` work, whereas `kimi-k3` and the Gemini models do not support streaming on AI Builder Space.

Local version (uses only the Python standard library; no packages to install):

```bash
# 1. Install llama.cpp. Mac: brew install llama.cpp; NVIDIA: build with CUDA per the llama.cpp repository instructions
# 2. Start the server in another terminal; the first run downloads the model automatically (--no-mmproj skips the unused vision weights)
llama-server -hf unsloth/Qwen3.5-2B-GGUF:Q4_K_M --no-mmproj -c 65536 -np 1 --port 8080
# 3. Run the experiments
python3 local_cache.py                    # If not on port 8080, add --url http://127.0.0.1:PORT
```

## What you should see

**Experiment 1 (varying input length)**: Time to First Token (TTFT) grows as the input gets longer. In the local run, you can see prefill throughput directly at several thousand tokens per second.

**Experiment 2 (varying output length)**: Total time grows almost linearly with output length, while time per output token stays nearly flat. Decode runs at one to two hundred tokens per second, more than an order of magnitude slower than prefill. That reflects the two distinct computation regimes: prefill processes the entire input prompt in parallel in one shot, whereas decode can only produce one token per step sequentially.

**Experiment 3 (prefix caching)**: With the append-only pattern, TTFT drops sharply starting on Turn 2. With the prepend-timestamp pattern, every turn is just as slow as Turn 1, because changing the start of the prompt invalidates the entire cached prefix behind it.

Our reference outputs (recorded on 2026-10-23) are in `sample_output/`:

| | Append-only (Turn 2 onward) | Prepend-timestamp (Turn 2 onward) |
|---|---|---|
| Local Mac Studio (M3 Ultra), `Qwen3.5-2B` `Q4_K_M`, ~51,000 tokens/turn | Recomputes 17 to 18 tokens/turn, reuses ~51,000, prefill 0.04 s | Recomputes ~51,000 tokens/turn, reuses 0, prefill ~14.2 s |
| Cloud API: `deepseek`, ~107,000 tokens/turn | Median TTFT 1.94 s | 3.16 s |
| Cloud API: `grok-4-fast`, ~101,000 tokens/turn | Median TTFT 1.80 s | 3.95 s |

Across all 6 local turns, total recomputed input tokens come to 51,222 for append-only versus 308,026 for prepend-timestamp, a 6x difference. Local decode stays steady at ~183 tokens/s (5.5 ms per token), while local prefill runs at ~1,703 tokens/s on a 1,041-token input and 3,635 to 5,293 tokens/s once GPU compute saturates (~4,900 tokens/s at 16,865 input tokens). On the cloud API with `deepseek`, median TTFT rises from 1.23 s at 2,185 input tokens (1.30 s at 9,200; 1.63 s at 77,591) to 3.63 s at 292,995 input tokens, and decode takes ~2.7 to 3.0 ms per output token across 200 to 800 output tokens.

Files in `sample_output/`:

- `local_qwen3.5-2b-q4km_m3ultra_20261023.json` and `local_m3ultra_console.txt`: Local Mac Studio (M3 Ultra) run across all three experiments, executed with English prompts over random ASCII filler text. The `.json` file stores raw `llama-server` timing records with English keys; `local_m3ultra_console.txt` is the console log from that run and uses Chinese table headings and unit labels.
- `api_deepseek_20261023.json` and `api_deepseek_console.txt` (all three experiments on `deepseek`), plus `api_grok-4-fast_cache_20261023.json` and `api_grok-4-fast_cache_console.txt` (Experiment 3 on `grok-4-fast`): Cloud API runs over random ASCII filler text paired with short Chinese prompt questions (`api_timing.py` keeps those exact prompt strings). The `.json` files store raw timings under English keys, while the two `*_console.txt` logs use Chinese headings and unit labels.

Cloud API timings include network and server-queueing jitter and can vary by half a second on the same turn, so focus on medians and trends rather than individual numbers.

**One limitation**: On AI Builder Space, `usage` returns only `prompt_tokens`, `completion_tokens`, and `total_tokens`. It does not report cached token counts or bill cache hits separately from cache misses, so `api_timing.py` can only observe prefix caching through latency, and cache hits on this gateway save wait time rather than money. When you call native provider endpoints directly (for example, DeepSeek's official API, which returns cache-hit token counts in `usage`), cache hits are billed at a steep discount, so the same difference between append-only and prepending a timestamp also shows up directly on your bill.

## Testing with your own data

Both scripts accept `--doc your_file.txt` to replace the long document in Experiment 3 with your own material, such as the system prompt, tool definitions, and project docs your agent includes on every turn. If you want to check whether your own agent is invalidating its prefix cache, the most direct check is to save the full prompt strings it actually sends on each turn and inspect `prompt_n` (recomputed tokens) and `cache_n` (cached tokens) turn by turn with `local_cache.py`. If `prompt_n` does not drop to a few dozen tokens from Turn 2 onward, something in the prefix is changing between turns, most commonly a live timestamp, a random ID, or a tool list re-ordered on every turn.
