Skip to content

1.6.0 has major cache-loss issues not seen in 1.5.0 on M5 Max #706

Open

Description

@tomchk

Hi, awesome engine here, but for the first time I am having a much worse experience using the latest version. I downgraded to 1.5.0 to confirm that it does not have this issue. Here is what I see very often when using 1.6.0 via ohmypi. I assume this is not intended behavior? It often loses the cache by a lot and has to re-prefill 100k+ tokens, which is of course a huge loss in speed. Any ideas or needed info? Thanks!

My Mac OS version is 27.0.1 (26A434). The model I am serving is https://huggingface.co/ISTA-DASLab/Qwen3.8-Flash-Next-GSQ-RCO-GGUF/tree/main/IQ3_S, split GGUF like downloaded in 1.4.0 or so.

22:08:56 Done · input 180,830 · cached 179,360 · deduplicated 1,024 · output 160 · tools 12·3d13e460 · TTFT 0.9s · 81.5 tok/s · 2.9 tok/cycle
22:08:57 Memory: in-service claim of request 407 needs 386.1 MiB: pending, took cache 0.0 cache 0.0 (113.2 MiB now, 0.0 later)
22:08:57 Memory: in-service claim of request 407 needs 386.1 MiB: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:08:57 Started · input 181,614 · cached 14,528 · effort xhigh · thinking on
22:08:59 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:08:59 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:03 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: pending, took embeddings unit 13.4 cache 0.0 (13.4 MiB now, 0.0 later)
22:09:03 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:06 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:09:06 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:10 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:09:10 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:13 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:09:13 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:16 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:09:16 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:20 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:09:20 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:23 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:09:23 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:26 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:09:26 Memory: in-service claim of request 407 needs 148.5 MiB, 47 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:30 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:09:30 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:33 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:09:33 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:36 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:09:36 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:40 Memory: in-service claim of request 407 needs 148.5 MiB, 41 pages: pending, took cache 0.0 cache 0.0 (2.8 MiB now, 0.0 later)
22:09:40 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:44 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:09:44 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:47 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:09:47 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:51 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:09:51 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:09:56 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:09:56 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:00 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:10:00 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:04 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:10:04 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:08 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:10:08 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:12 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:10:12 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:16 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:10:16 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:20 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:10:21 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:25 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:10:25 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:29 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:10:29 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:33 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:10:33 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:37 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:10:37 Memory: in-service claim of request 407 needs 148.5 MiB, 38 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:41 TTFT of request 407: 104215 ms: own prefill 103466, claim wait 675.269, decode 0, other prefill 0, rest 73.6485
22:10:53 Done · input 181,614 · cached 14,528 · output 978 · tools 12·3d13e460 · TTFT 104.2s · 80.6 tok/s · 2.6 tok/cycle
22:10:54 Started · input 181,795 · cached 14,528 · effort xhigh · thinking on
22:10:54 Memory: in-service claim of request 408 needs 148.5 MiB, 47 pages: pending, took cache 0.0 cache 0.0 (0.0 MiB now, 0.0 later)
22:10:54 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:10:58 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: pending, took embeddings unit 1.6 cache 0.0 (1.6 MiB now, 0.0 later)
22:10:58 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:01 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:11:01 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:05 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:11:05 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:09 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:11:09 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:13 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:11:13 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:17 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:11:17 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:21 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:11:21 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:24 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:11:24 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:29 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: pending, took cache 0.0 (2.8 MiB now, 0.0 later)
22:11:29 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:32 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:11:33 Memory: in-service claim of request 408 needs 148.5 MiB, 11 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:37 Memory: in-service claim of request 408 needs 148.5 MiB, 17 pages: pending, took cache 0.0 cache 0.0 (2.8 MiB now, 0.0 later)
22:11:37 Memory: in-service claim of request 408 needs 148.5 MiB, 8 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:40 Memory: in-service claim of request 408 needs 148.5 MiB, 2 pages: pending, took cache 0.0 (0.0 MiB now, 0.0 later)
22:11:40 Memory: in-service claim of request 408 needs 148.5 MiB, 2 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)
22:11:44 Memory: in-service claim of request 408 needs 148.5 MiB, 8 pages: pending, took cache 0.0 cache 0.0 (2.8 MiB now, 0.0 later)
22:11:46 Memory: in-service claim of request 408 needs 148.5 MiB, 58 pages: met, took cache 0.0 (113.2 MiB now, 0.0 later)

Activity

  1. TBMoonwalker commented on Nov 7, 2026

    @TBMoonwalker

    Same here with a M5 Max:

    07:31:37 Done · input 235,414 · cached 232,544 · deduplicated 2,816 · output 1,650 · tools 12·aee039ed · TTFT 17.2s · 49.8 tok/s · 6.0 tok/cycle
    07:31:37 Started · input 237,109 · cached 235,392 · effort xhigh · thinking on
    07:31:37 Memory: in-service claim of request 246 needs 130.0 MiB, 42 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:31:37 Memory: in-service claim of request 246 needs 152.6 MiB, 1 state buffers: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:31:37 Memory: optional claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:31:48 TTFT of request 246: 10564 ms: own prefill 10563.4, claim wait 0, decode 0, other prefill 0, rest 0.534792
    07:32:22 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:22 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:23 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:23 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:24 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:24 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:25 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:26 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:26 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:27 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:28 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:28 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:29 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:29 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:30 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:30 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:31 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:32 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:33 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:33 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:34 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:35 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:35 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:36 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:36 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:37 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:37 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:38 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:38 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:39 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:40 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:40 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:40 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:41 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:42 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:42 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:43 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:44 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:44 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:45 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:45 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:46 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:47 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:47 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:48 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:49 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:50 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:50 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:51 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:52 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:52 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:53 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:53 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:54 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:54 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:55 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:55 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:56 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:56 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:57 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:57 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:58 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:58 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:59 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:32:59 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:00 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:00 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:01 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:02 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:02 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:03 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:03 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:04 Memory: in-service claim of request 246 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:05 Done · input 237,109 · cached 235,392 · deduplicated 1,664 · output 3,996 · tools 12·aee039ed · TTFT 10.6s · 51.9 tok/s · 6.3 tok/cycle
    07:33:05 Started · input 241,133 · cached 237,088 · effort xhigh · thinking on
    07:33:05 Memory: in-service claim of request 247 needs 130.0 MiB, 63 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:17 Memory: in-service claim of request 247 needs 152.6 MiB, 1 state buffers: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    07:33:30 TTFT of request 247: 24665.6 ms: own prefill 24665, claim wait 0, decode 0, other prefill 0, rest 0.684084

  2. wanglijian-hue commented on Nov 7, 2026

    @wanglijian-hue

    Same symptom here, on a different setup — and with a control experiment that may help narrow it down.

    Setup: Splash 1.6.0 standalone (arm64-macos26), Mac Studio M5 Ultra / 96 GB, serving a 122B MoE GGUF (Q3_K_XL) at ctx 262144, --max-memory 86G (capped by the Metal budget), --kv-format int8 (default), --idle-release off. Weights fit in memory, so no expert streaming: our log contains zero Memory: in-service claim ... lines, yet the cache loss still happens with real agent traffic.

    What we see (client keeps a ~180K-token conversation):

    18:54:19 Started  input 179,054  cached 0        (cold, own prefill 147 s, gave up after 158 s)
    18:56:46 Started  input 178,977  cached 178,944  Done, TTFT 35.9 s (35.5 s "other prefill" — waiting on the one above)
    18:57:40 Started  input 179,585  cached 0        TTFT 147.7 s, cancelled
    19:09:36 Started  input 179,585  cached 0
    19:11:10 Started  input 179,585  cached 0
    19:12:47 Started  input 179,585  cached 0
    19:13:08 Started  input 179,585  cached 0
    

    The important part: at 18:56 a 178,977-token request completed successfully (output 556). One minute later a 179,585-token request from the same conversation starts at cached 0 — i.e. the KV that was just resident was not reused at all, even though the new prompt shares its whole 178,977-token prefix.

    Control on the same 1.6.0 build, plain HTTP client (no agent):

    input 172,521  cached 0        TTFT 136.9 s   (cold)
    input 172,521  cached 172,512  TTFT 0.4 s     (identical replay)
    input 172,522  cached 172,512  TTFT 0.8 s     (+1 char at the end)
    

    So the prefix-cache machinery itself works at 172K on this build. The loss only shows up with the real agent client (tools present, effort low, thinking on), which suggests it is tied to whatever else the agent traffic does between turns (concurrent requests / cancellation / tool results) rather than to a size limit.

    After downgrading to 1.5.0 the same ~180K conversation hit the cache and answered in 0.1 s on the next turn, so this is specific to 1.6.0.

    Also note: on 1.6 we never got a Memory: line, so the expert-store reclamation path visible in @TBMoonwalker's log may not be the only trigger.

    Happy to run instrumented tests on 1.6.0 if you tell me what to capture (we can reproduce on demand and keep 1.5.0 live for comparison).

  3. tomchk commented on Nov 7, 2026

    @tomchk
    Author

    Glad I'm not the only one! My Mac OS version is 27.0.1 (26A434). The model I am serving is https://huggingface.co/ISTA-DASLab/Qwen3.8-Flash-Next-GSQ-RCO-GGUF/tree/main/IQ3_S, split GGUF like downloaded in 1.4.0 or so. Thanks!

  4. dm1try commented on Nov 7, 2026

    @dm1try

    We couldn't reproduce this on a Mac Studio M5 Ultra 96 GB (Flash-Next Q2_0, expert streaming). No request lost the cache on 1.6.0 in any scenario we tried, and 1.5.0 matched on the ones we also ran there (details below).

    On Flash-Next, cached N in the Started line is where the request resumes: the deepest saved recurrent state on the matched KV, not the length of the KV match. So a low cached alone doesn't show whether the prompt changed or the server dropped KV/states.

    @tomchk @wanglijian-hue, could you capture GET /status right before and after a losing request, with nothing else running? The counters are cumulative. Here's how we expect them to read, going by the code; we haven't seen a loss to check this against:

    • cache.kv_hit_tokens grows by the KV that request matched. If it's close to the previous request's length while cached is low, the states were missing.
    • cache.lost_state_misses +1 means a state that existed was dropped.

    Two consecutive request bodies would show whether the client changed the prompt. Which API does your agent use: Chat Completions, Messages or Responses?

    What we tried

    Setup: release tarballs, Flash-Next Q2_0 GGUF, and --max-memory 30G (expert streaming on, Memory: in-service claim lines present; 1.6.0 also ran at 22G). The client was a script over Chat Completions and Messages, with 40 tools and thinking on. Each turn fed back the model's own reasoning and tool calls. Context ran from 110K to 200K tokens.

    These kept the cache on 1.6.0:

    • sequential turns;
    • a cancel during prefill, and a cancel during decode;
    • comment 2's sequence: a cold 170K prefill dropped just after its first token while a retry of the same turn waited on it. The retry got 173,952 cached, and so did the next turn;
    • side and recap requests overlapping a prefill;
    • a mid-conversation system message;
    • Messages with display: omitted thinking;
    • a server restart between turns with --persistent-cache.

    These gave the same results on 1.5.0:

    • sequential turns;
    • a cold-prefill cancel;
    • comment 2's sequence;
    • Messages, including omitted thinking and the restart.

    lost_state_misses and replay_state_publication_failures stayed 0 throughout. Not covered: the Responses API, IQ3_S, and machines with less than 96 GB.

    🤖 Prepared by Claude · 👤 Confirmed by me

  5. TBMoonwalker commented on Nov 7, 2026

    @TBMoonwalker

    Don't know if I did it right.

    Before cache loss messages:

    {
    "probe_hashed_blocks": 767261,
    "hits": 178,
    "cold_misses": 4,
    "hit_rate": 0.978021978,
    "kv_hit_tokens": 23446080,
    "kv_disk_hit_tokens": 0,
    "lost_state_misses": 0,
    "reused_tokens": 23285536,
    "deduplicated_kv_tokens": 158944,
    "replay_state_publications": 182,
    "deduplicated_state_publications": 0,
    "recycled_state_publications": 9,
    "disk_state_publications": 0,
    "state_captures": 208,
    "capture_cuts": 0,
    "replay_state_publication_failures": 0,
    "lazy_junctions": 3,
    "junction_materializations": 1,
    "junction_materialization_failures": 0,
    "checkpoint_publications": 43,
    "checkpoint_publication_failures": 0,
    "resource_suspensions": 0,
    "priority_suspensions": 0,
    "resource_resumptions": 0,
    "resource_replay_tokens": 0
    }

    Starting getting the messages:

    19:19:14 Memory: in-service claim of request 184 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)
    19:19:16 Memory: in-service claim of request 184 needs 130.0 MiB, 1 pages: met, took cache 0.0 (0.0 MiB now, 0.0 later)

    After that:

    {
    "probe_hashed_blocks": 779237,
    "hits": 180,
    "cold_misses": 4,
    "hit_rate": 0.9782608696,
    "kv_hit_tokens": 23829248,
    "kv_disk_hit_tokens": 0,
    "lost_state_misses": 0,
    "reused_tokens": 23668160,
    "deduplicated_kv_tokens": 159488,
    "replay_state_publications": 184,
    "deduplicated_state_publications": 0,
    "recycled_state_publications": 11,
    "disk_state_publications": 0,
    "state_captures": 210,
    "capture_cuts": 0,
    "replay_state_publication_failures": 0,
    "lazy_junctions": 3,
    "junction_materializations": 1,
    "junction_materialization_failures": 0,
    "checkpoint_publications": 43,
    "checkpoint_publication_failures": 0,
    "resource_suspensions": 0,
    "priority_suspensions": 0,
    "resource_resumptions": 0,
    "resource_replay_tokens": 0
    }

  6. jianc99 commented on Nov 8, 2026

    @jianc99
    Collaborator

    Thanks all for the detailed reports, and @TBMoonwalker for the snapshots.

    We tried to reproduce this deterministically in engine tests:

    • On Flash-Next, cached in the Started line is the deepest saved state on the matched KV. A turn whose prompt departs from the previous one before its end resumes at the deepest state saved below that point, such as the branch point where the system prompt and tools end (likely 14,528 in @tomchk's log), or at 0. Nothing was lost from the cache.
    • Memory pressure lost nothing, with one exception: a new turn that hits the memory limit with nothing else running can lose its resume point. It then logs Memory: in-service claim of request N … short before its Started line and usually fails later. Your logs show neither.
    • 1.6.0 places and retires checkpoints exactly as 1.5.0 does: a prefill keeps only its last one.

    @TBMoonwalker: you did it right. Between your snapshots there were two hits: kv_hit_tokens +383,168, reused_tokens +382,624, lost_state_misses still 0. Both turns resumed within a few hundred tokens of their KV match, so that window lost nothing. The Memory: … took cache 0.0 lines are claims that reused pages or state buffers the cache held. 0.0 is the MiB they freed, and your counters show both turns still found their resume points.

    Common client-side causes in agent harnesses:

    • per-request content in the system prompt (time, working directory, git status, todo lists);
    • pruning or compacting old tool results;
    • dropping or rewriting earlier thinking;
    • reordered tools (the tools N·hash in the Done line changes).

    Telling them apart, for a turn whose cached is far below the previous prompt:

    • kv_hit_tokens grows by about the previous prompt's length, or lost_state_misses / replay_state_publication_failures rise: the engine lost a state. That's on us.
    • It grows by about cached, or by a mid-history point: the prompt changed there, or the cache evicted what followed. Two request bodies tell which.
    • In the Done line, cached + deduplicated ≈ how far the prompt matched the KV still in RAM. @tomchk's 407 shows no deduplicated, which suggests its prompt stopped matching just past 14,528.

    Could you send one /status before/after pair around such a turn, with its Started and Done lines, plus the client name, version and API? Or two consecutive request bodies. @tomchk: 408's Done line would help too.

    @wanglijian-hue: your 122B has no expert streaming and no Memory: lines, which fits a prompt change rather than memory pressure. In our tests a same-length edit early in the prompt (a timestamp, say) starts at cached 0. Your control only appended at the end; edits inside the history are what fall back. The same counters apply. Since you keep 1.5.0 live: capture the last good request body and the one that goes cold, then send that pair in order to each version from a fresh start. If only 1.6.0 goes cold, it's ours.

    Thanks again for your patience and for the careful logs; they made this much easier to dig into.

  7. TBMoonwalker commented on Nov 8, 2026

    @TBMoonwalker

    @jianc99 thanks for the update. I'm using the unsloth/Qwen3.8-27B-GGUF:UD-Q4_K_M model with OpenCode Desktop 2.2.5. Trying to catch the status during such a turn. I think I've seen it after a compaction.

    Agent Skillset ist from GStack

  8. tomchk commented on Nov 8, 2026

    @tomchk
    Author

    Sorry, I don't see a log file anywhere with 408. Does splash keep logs somewhere by default? I couldn't tell from a couple quick searches.

    Could you send one /status before/after pair around such a turn, with its Started and Done lines, plus the client name, version and API? Or two consecutive request bodies. @tomchk: 408's Done line would help too.

  9. jianc99 commented on Nov 8, 2026

    @jianc99
    Collaborator

    @tomchk splash serve prints its log to the terminal and keeps no file of its own. If you start it from the Mac app, the log is in ~/Library/Logs/Splash/server.log. From a terminal, you can keep one with splash serve ... 2>&1 | tee ~/splash.log.

    @TBMoonwalker Thanks. A compaction rewrites the conversation, so the prompt changes from the summary on, and the next turn can't reuse the cache past that point. That one is expected. A drop on a turn without a compaction is the case we'd like to see.

  10. wanglijian-hue commented on Nov 9, 2026

    @wanglijian-hue

    Thanks @jianc99 — your explanation sent us back to test the right thing, and you are partly right: our original report was incomplete. We captured the actual request bodies and re-ran the comparison. Results below.

    Setup. Same machine as before: M5 Ultra, 96 GB, Ornith-1.5-122B Q3_K_XL, ctx 262144, no expert streaming. Splash 1.5.0 and 1.6.0 on the same install, one engine at a time, each started fresh.

    Method. A capture proxy in front of the router logged the exact JSON bodies Hermes sent on two consecutive turns of one session. We then replayed those two bodies, in order, into each engine from a freshly started process: everything unloaded, engine started, body A sent, body B sent.

    The client is append-only here. Request B shares its first 20,149 bytes with request A byte for byte; the first differing byte is exactly where the assistant message is appended. system (18,051 chars), tools, model and reasoning_effort are identical between the two.

    Results — identical on both versions:

    1.5.0 fresh  A: prompt 15,370  cached 0        TTFT 4.7 s
                 B: prompt 15,408  cached 15,360   TTFT 0.1 s  (99.7%)
    
    1.6.0 fresh  A: prompt 15,370  cached 0        TTFT 4.7 s
                 B: prompt 15,408  cached 15,360   TTFT 0.1 s  (99.7%)
    

    On append-only traffic we cannot reproduce a 1.6-specific cache loss. That part of our original claim does not hold, and I withdraw it.

    What we did find is on the client side. Hermes can invalidate the whole prefix itself, mid-session, by changing the system prompt. From its log on the machine where the original 179K requests went cold:

    18:54:08 Session a94287a9b01e: skills changed (+2/-0) since the system prompt
             was built; delivering the change as a turn note (prefix cache pres...
    

    Two skills were installed mid-session, the skills block in the system prompt changed, and the next 179,585-token request started at cached 0. This is version-independent — 1.5.0 would behave the same. It matches your reading: no KV state was corrupted, the prompt changed.

    One correction to our own data. We also said 1.6 "failed to start" during this test (native protocol reached EOF, stopped after 3 failures in 60 s). That was our harness, not 1.6: we killed the serve-native process without its server, the server counted each death as a crash, and after the third it stopped relaunching — while splash.sh, seeing the port still bound, reported "already running". With the server killed as well, 1.6.0 loads and serves normally (203 tok/s on a short prompt). There is no launch regression to report.

    Still open. The original incident also had one case where 18:56 completed with cached 178,944 and the 18:57 request (same session, +608 tokens) started at cached 0. We have not explained that one yet. Candidates are a second skills/tool-set change or a compaction rebuild. We will capture bodies across such an event and post them if we catch it.

  11. TBMoonwalker commented on Nov 14, 2026

    @TBMoonwalker

    @jianc99 can't reproduce the messages anymore since the new 1.6.1 release.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions