Metal 第一次运行要好几秒
主线位置:推理主线的第一个 token,落在算子主线的 Metal 一步。
MetalStorage::matmul等每个 op 要先拿到内核管线,第一次碰到某个.metal源文件时要把整个文件交给 Metal 编译;机制、两级缓存和每个库的冷启动时间见 Metal 后端,一次生成里各阶段的冷热对比见生成一个 token。
flowchart TB
op["第一次 matmul"] --> k{"进程内有这个库"}
k -->|有| run["几毫秒"]
k -->|没有| os{"系统缓存命中"}
os -->|命中| fast["每个库 2 到 3 ms"]
os -->|未命中| slow["整文件编译 秒级"]
w["启动时预热"] --> k
实验 crate exp-candle/pa-gen(candle-metal-kernels 换成了一份打补丁的副本,源码与 0.11.0 相同,只多两样:INTRO_TRACE 打印每个库的编译时间,INTRO_NONCE 在源码末尾加一行注释,让系统缓存必然不命中),bin p09_first,release;M2 Max、macOS 27、rustc 1.99.0。测量时机器上还有别的任务,uptime 的 1 分钟负载在 1.5 到 12 之间。
现象
一个最小的「服务」:加载 SmolLM2-135M 的 Q8_0 GGUF,然后连续处理三个相同的请求,每个请求 prefill 一段 prompt 再贪心生成 10 个 token:
let t = Instant::now();
let mut f = BufReader::new(std::fs::File::open(format!("{DIR}/SmolLM2-135M-Instruct-Q8_0.gguf"))?);
let content = gguf_file::Content::read(&mut f)?;
let mut model = ModelWeights::from_gguf(content, &mut f, &dev)?;
dev.synchronize()?;
println!("load model: {:>8.1} ms", t.elapsed().as_secs_f64() * 1e3);
// ...
for req in 1..=3 {
let t = Instant::now();
let out = generate(&mut model, &prompt, 10, &dev)?;
// ...
}
系统缓存不命中(冷)和命中(热)各一次:
### cold (INTRO_NONCE), no warm-up
load model: 4317.6 ms
request 1 (10 tok): 8341.7 ms "Rust is a modern, high-performance,"
request 2 (10 tok): 36.3 ms "Rust is a modern, high-performance,"
request 3 (10 tok): 35.0 ms "Rust is a modern, high-performance,"
### warm, no warm-up
load model: 122.5 ms
request 1 (10 tok): 58.0 ms "Rust is a modern, high-performance,"
request 2 (10 tok): 36.4 ms "Rust is a modern, high-performance,"
request 3 (10 tok): 35.8 ms "Rust is a modern, high-performance,"
冷的时候,一个 135M 的小模型加载要 4.3 秒,第一个请求 8.3 秒,是之后请求的 230 倍。热的时候第一个请求也比之后多 22 ms(58 ms 对 36 ms)。
出处
INTRO_TRACE=1 打出冷启动时每个库的编译时间(只保留 LIB 行):
LIB Cast 78.4 ms
LIB Gemm 3846.3 ms
LIB Unary 119.7 ms
load model: 4169.9 ms
LIB Indexing 71.1 ms
LIB Reduce 4394.6 ms
LIB Quantized 809.1 ms
LIB Affine 32.2 ms
LIB Ternary 46.5 ms
LIB Binary 578.3 ms
LIB Sdpa 2122.2 ms
request 1 (10 tok): 8133.0 ms "Rust is a modern, high-performance,"
- 加载阶段的 4.2 秒几乎全是
mlx_gemm.metal(3.8 s):from_gguf里算 RoPE 的频率表用了一次matmul。 - 第一个请求的 8.1 秒是另外 7 个库:
reduce.metal(4.4 s,softmax、rms_norm 都在里面)、scaled_dot_product_attention.metal(2.1 s,decode 时走sdpa)、quantized.metal(0.8 s)、binary.metal(0.6 s)等,加起来 8.05 s。
Kernels::load_library 第一次碰到某个 Source 就把整个文件交给 newLibraryWithSource,编译结果存在这个 MetalDevice 的 Kernels 里;candle 0.11.0 不带预编译的 .metallib,没有构建期编译这条路。跨进程的缓存是 macOS 自己的,命中时每个库 2 到 3 ms,上面「热」那次就是这样;但它不保证命中(Metal 后端记录了复制二进制、改编译选项、机器负载高时的未命中)。热的时候第一个请求为什么仍多出 20 多毫秒?再跑一次热的,按阶段汇总 LIB 和 PIPE 行(括号里的行是用 awk 从这两类行算出来的,不是程序的原始输出):
load model: 125.7 ms
(4 PIPE 0.7 ms, 3 LIB 3.2 ms before this)
request 1 (10 tok): 56.4 ms "Rust is a modern, high-performance,"
(17 PIPE 0.2 ms, 7 LIB 7.1 ms before this)
request 2 (10 tok): 32.4 ms "Rust is a modern, high-performance,"
(0 PIPE 0.0 ms, 0 LIB 0.0 ms before this)
第一个请求从系统缓存取 7 个库花了 7.1 ms,建 17 个管线 0.2 ms,合计约 7 ms;多出的其余十几毫秒不在编译上,本页没有再追。
修法
启动时预热。 加载完模型,用两个 token 的 prefill 加一步 decode 跑一遍,所有请求会用到的内核都在这一步编译、建管线:
if warmup {
let t = Instant::now();
// two tokens of prefill and one decode step touch every kernel a request uses
generate(&mut model, &prompt[..2], 2, &dev)?;
println!("warm-up: {:>8.1} ms", t.elapsed().as_secs_f64() * 1e3);
}
### cold (INTRO_NONCE), WARMUP=1
load model: 4246.5 ms
warm-up: 7988.3 ms
request 1 (10 tok): 41.0 ms "Rust is a modern, high-performance,"
request 2 (10 tok): 32.4 ms "Rust is a modern, high-performance,"
request 3 (10 tok): 33.1 ms "Rust is a modern, high-performance,"
### warm, WARMUP=1
load model: 125.6 ms
warm-up: 35.2 ms
request 1 (10 tok): 34.8 ms "Rust is a modern, high-performance,"
request 2 (10 tok): 33.2 ms "Rust is a modern, high-performance,"
request 3 (10 tok): 33.3 ms "Rust is a modern, high-performance,"
预热不减少总时间,只是把它挪到启动时、挪出用户请求。冷的时候第一个请求从 8.3 s 降到 41 ms;热的时候预热只要 35 ms,第一个请求和之后的一样。
预热输入要覆盖真实请求走的分支:quantized_llama 在 seq_len > 1 时建 mask、走 softmax,seq_len == 1 时在 Metal 上走 sdpa(见量化 llama 的一次前向),所以预热里 prefill 和 decode 各至少一步。加了 INTRO_TRACE 再跑一次冷启动加预热,第一个请求里新编译的库和新建的管线都是 0 个;它仍比之后的请求慢 5 到 9 ms,和上面热启动时那十几毫秒一样,不是编译。
其他几点:
Kernels每个MetalDevice一份,只建一个设备(见 device mismatch in add),预热才对之后所有请求有效。- 命令行工具每次都是新进程,只能靠系统缓存。别改
CANDLE_METAL_ENABLE_FAST_MATH之类影响编译选项的环境变量,它们是缓存键的一部分,改了就是冷的。 - 计时、做基准时把第一次单独列出来并写明冷热,见 Metal 上计时几乎为零。
怎么确认没中招
- 服务启动日志里有一行预热耗时;首个请求的延迟和之后的同一个量级。
- 怀疑是编译时,看时间是不是落在「第一次用到某类 op」上(第一次 matmul、第一次 softmax),并且第二个请求恢复正常。
- 要稳定复现冷启动,就得让系统缓存不命中;本页用的是在源码末尾加注释的补丁,改编译选项(
CANDLE_METAL_ENABLE_FAST_MATH=false)第一次也能做到,但第二次就热了。
小结
- candle 的 Metal 内核在运行期按文件编译,第一次用到 GEMM、归约、SDPA 各要几秒,SmolLM2 冷启动加载 4.3 s、第一个请求 8.3 s。
- macOS 跨进程缓存命中时每个库只要几毫秒,但不保证命中。
- 修法是启动时用覆盖 prefill 和 decode 的小输入预热;它把编译挪出请求路径,不减少总时间。