Kotonia Articles

同じLoRAなのにキャッシュを捨てていた——3万トークンの読み直しをllama.cppまで追った話

特定の人が話すと全員が遅くなる。原因を追うと、llama-serverがRAMから戻したばかりのキャッシュを自分で捨てていた。外れ率77%の調査から、本家PRに回帰テストが入るまでの記録。

著者清水真二2026-11-077分で読める

#llm#llamacpp#lora#パフォーマンス#個人開発

他の言語英語中国語

はじめに

自宅のGPU 2枚でローカルLLMを動かして、キャラクターチャットのサービスを運営している。モデルはGLM-5.3-Flashの3bit GGUFで、llama-serverの4スロット構成だ。

ある日、気になっていたことを調べてみた。特定の利用者が話している間、全員の推論がとても遅くなる。

原因は、その人の使い方でも、GPUの能力でも、キャッシュの容量でもなかった。llama-serverが、RAMから正しく戻したばかりのキャッシュを、次の行で自分で捨てていた。

RAMキャッシュから戻す経路の外れ率（3,000トークン以上）

LoRAなし  42%（55回中23回）
LoRAあり  77%（79回中61回）

修正後、LoRAありの外れ率は同じ集計で15〜22%まで下がった。本家にも同じ方針のPRがすでに出ていて、本番の症状を再現する回帰テストをコメントで提案したところ、そのPRに取り込まれた。PR自体はレビュー待ちで、2026-11-07時点ではマージされていない。

この記事は、そこまでの調査の記録だ。途中で外した仮説も全部書く。

症状

その利用者の使い方はテキストだけで、音声も画像生成も使っていなかった。プロンプトは中央値で3.2万トークン。長い会話を続けている人だ。

16時間のログを見ると、40ターン中25回でキャッシュが外れ、そのたびに40〜68秒のprefillが走っていた。他の利用者への影響は次のとおり。

状況（直近3日、1字あたりの生成時間）	件数	中央値	p90
どちらも動いていない	1,025	24.5 ms	66 ms
その人が生成している	29	61.3 ms	204 ms

サンプルが少なく、長いリクエストほど重なりやすい偏りもあるので、倍率は粗い数字だ。それでも、prefillが重なった時間帯には生成速度が58 tok/sから19 tok/sまで落ちていた。

prefillが他の人の生成を止める仕組みは別の問題なので、別の記事に書いた。この記事で追うのは、そもそも、なぜ3万トークンを毎回読み直しているのかだ。

仮説1: キャッシュの容量が足りない

llama-serverのログには、古いエントリを追い出す行が並んでいた。

alloc: - making room for prompt cache entry, removing oldest entry (size = 747.843 MiB)

RAMのプロンプトキャッシュが上限に張り付いている。これが原因に見えた。

ここで最初のミスをした。Claudeと調べていて、「--cache-ram を指定していないから上限は既定の8 GiB」と読み、16 GiBへの増設を勧められた。実際はすでに16 GiBだった。実物の値を見ずに、既定値から説明を組み立ててしまった例だ。

それより大事なのは、数えると容量説が成り立たなかったことだ。3,000トークン以上の639ターンをスロットの選ばれ方で分けた。

スロットの選ばれ方	ヒット	外れ
LCP（会話がGPUのスロットに残っていた）	381	10
LRU（スロットは他に使われ、RAMから戻す経路）	107	114

外れはほぼRAM経由に集中している。ただ、5分未満の間隔で話しているのに外れたターンが58回あった。1エントリ600〜1,000 MiB、追い出し間隔の中央値5.3分なら、1つの会話は50分以上キャッシュに残る計算で、5分で消えるはずがない。前のターンとの間に追い出しが挟まっても挟まらなくても、外れ率は同じ約33%だった。

容量を増やしても、この58回は直らない。

仮説2: 再生成で履歴が変わっている

私の予想はこれだった。再生成やメッセージの削除で履歴が分岐すると、キャッシュは当たらないはずだ。

半分は当たっていた。再生成は24回中8回外れた。ただ、全体から見ると少数で、一番多かったのは「普通に会話が続いて、プロンプトが伸びただけなのに外れる」ケースだった。

ログが無い。TRACEにもできない

判定の過程が見たいが、「どのキャッシュ候補と比べたか」「checkpointから戻したか」といった行は TRACE レベルだった。

ここに罠がある。TRACEを有効にするとDEBUGも出て、プロンプトのトークンがすべてログに残る。 サービスの本番で、利用者の会話をjournalに流すわけにはいかない。

そこで、位置とサイズだけを出す9行を、forkで INFO に上げた。

- SRV_TRC(" - looking for better prompt, base f_keep = %.3f, f_sim = %.3f\n", ...);
+ SRV_INF(" - looking for better prompt, base f_keep = %.3f, f_sim = %.3f\n", ...);

すると、奇妙な例が出た。あるターンは97%一致するエントリ（39,027トークン中37,906）を見つけて戻したのに、そのあと3.9万トークンを頭からprefillして68秒かかっていた。checkpointから戻したログも、「全部やり直す」というログも出ていない。

戻せている。なのに、使われていない。

原因: 戻した直後に自分で捨てている

LoRAが怪しいと気付いて、LoRAの有無で分けた。このサービスは当時、リクエストごとに lora を指定して一部のキャラクターのターンにだけ当てていた。

	同じスロットに残っていた	RAMから戻した
LoRAなし	外れ 3%	外れ 42%
LoRAあり	外れ 4%	外れ 77%（79回中61回）

右下だけが突出している。コードを読むと、こういう流れだった。

LoRAの設定はスロットごとに持っていて、キャッシュのエントリには保存されない
LoRA付きの会話が追い出されたあと、別の人がそのスロットをLoRAなしで使う
元の会話が戻ってくる。状態はRAMから正しく戻る
しかしスロットには、直前の人の設定（LoRAなし）が残っている
launch_slot_with_task が「LoRAが変わった」と判定し、戻したばかりの状態を消す

if (!are_lora_equal(task_loras, slot.lora)) {
    if (lora_should_clear_cache(slot.lora, task_loras)) {
        SLT_TRC(slot, "clearing cache for lora change...");  // ← TRACEなので見えない
        slot.prompt.clear();
    }
    ...
}

同じLoRAの状態を、同じLoRAのリクエストのために戻したのに、無関係な前の利用者の値と比べて捨てている。ログはTRACEなので、何も出ない。

数字をもう一度疑う

42%と77%の組み合わせには、私が「比率の問題では？」と引っかかった。そもそも当たるはずのないターンが混ざっているのではないか、という疑問だ。

数え直すと、その通りだった。

	最初のLLMターン	要約の直後	100分以上空いた	会話の続き
LoRAなし	10回中10回	—	2回中2回	37回中10回（27%）
LoRAあり	4回中4回	3回中3回	4回中4回	52回中35回（67%）

LoRAなしの42%は、原理的に当たらないターンでかなり水増しされていた。当たるはずの「会話の続き」だけで比べると、27%と67%になる。LoRAの影響は、このおよそ40ポイントの差としてはっきりした。

修正

方針は単純で、「どのLoRA設定で計算した状態か」をキャッシュのエントリに一緒に保存する。

エントリにLoRA設定を持たせる
戻すときは、リクエストと設定が一致するエントリだけを候補にする
戻したら、スロットの設定もエントリに合わせる
LoRA付きで計算した状態を、LoRAなしのリクエストに使い回さない

どのLoRAを当てるかは、これまでどおりリクエストごとに決まる。

合成リクエストで試すと、6,036トークン中6,023トークンを再利用できた。本番でも、RAMから戻す経路で7,137トークンを再利用してprefill 1.5秒、8,635トークンを再利用して1.7秒という例が出た。

ついでに見つかった、監視による追い出し

新しいログには、もう1つ変なものが映っていた。21トークンの小さなリクエストが約6.5分おきに来て、大きな会話のスロットを持っていく。

犯人は自分の死活監視だった。理由が2つ重なっている。

チャットテンプレートの先頭だけで一致率が42%になり、しきい値の10%を超えるので、大きな会話のスロットが「似ている」と判定される
--kv-unified のこの版では、タスクが始まるたびに、空いているスロットをすべてRAMへ退避していた

最初は「監視を専用経路に分ける」「単発のリクエストを判定する」といった案を考えたが、当てる必要は無かった。プロンプトが短ければ、KVのセルをほとんど使わない。 256トークン未満のタスクは、空いている会話を退避させず、大きな会話のスロットも奪わないようにした（forkのみ）。修正後は、監視の直後でも会話がスロットに残り、RAMから戻す処理すら要らなくなった。

本家の該当部分はすでに作り直されていて、この修正はたぶん必要ない。ただ、確認まではしていない。

本番の結果

修正前と同じ集計を、修正後のログで取り直した。修正前の表は、当時のログを今回もう一度集計して、同じ値を確認している。

RAMから戻す経路の外れ率	修正前（16時間）	修正後（11/1〜2、約25時間）	その後（11/2〜6）
LoRAなし	42%（23/55）	36%（18/50）	21%（81/383）
LoRAあり	77%（61/79）	22%（17/77）	15%（68/459）

「会話の続き」だけで見ると、修正後（11/1夕方〜11/6）の外れはLoRAなしで3.5%（33/932）、LoRAありで2.9%（35/1,197）だった。LoRAの有無による差は消えている。

修正後に残った外れの多くは、仕組み上避けられないものだ。

修正後の外れ（3,000トークン以上）	LoRAなし	LoRAあり
セッション最初のターン	74/80	32/40
履歴の要約の直後	10/10	24/28
100分以上空いた	14/20	13/20

要約は履歴の先頭に差し込むので、そこから後ろが全部変わる。30Kトークン級の会話では、ここでの全prefillに1分前後かかる。これは今も残っている課題だ。

この比較には注意点がいくつかある。

「会話の続き」の前後比較は、集計方法が違う。 修正前は時刻でDBと突き合わせた推定で、修正後はセッションIDの付いたログだ
LoRAの修正と監視の修正は同じ日に入れたので、効果を分けられない。 監視の追い出しが無くなると、当たりやすいターンがRAM経路から抜けるので、RAM経路の外れ率の意味も少し変わる
11/2に、RAMキャッシュの上限を24 GiB、共有KVを256Kへ広げた。 右端の列にはこの影響が混ざる
利用者の構成も日によって違う。修正前の16時間と同じ負荷で測り直したわけではない
集計は11/6の未明までで切った。 その後、LoRAをほぼ全ターン共通の設定に変えたので、この経路の比較には使えない

本家に報告しようとしたら、PRがもうあった

本家のコードにも同じ処理が残っていたので、PRを出すつもりで準備を始めた。ところが、同じ方針の PR #30275 が10月10日から出ていた。

このPRの動機は #30129 の「違うLoRAのKVが混ざる」という正しさの問題だ。私たちが見たのは「同じLoRAのKVが毎回捨てられる」という性能の問題で、根は同じだが症状は逆向きになる。PRのテストは前者を確かめるものだった。

llama.cppのコントリビューション方針も確認した。

重複するPRは出さず、既存のPRにコメントする
AIが書いたコードは、開示すれば使ってよい
issue、PR、コメント、コミットメッセージの文章をAIに書かせるのは禁止

そこで、Claudeには再現環境、テストコード、数字の整理までを担当してもらい、コメントの文章は私が自分で書いた。自分の英語を見てもらって指摘されたのは、「hit rateではなくmiss rate」「72%は77%の打ち間違い」といった事実の誤りだ。本番で確かめたのは自分のforkで、PR自体を本番で試したわけではないので、「これで全部直る」とは書かないようにも指摘された。

テストはこれだけだ。スロットを1本にして、LoRAあり → LoRAなし → LoRAありと流す。

def test_lora_ram_prompt_cache_restore_same_lora():
    global server
    server.n_slots = 1
    server.n_ctx = 2048
    server.n_predict = 4
    server.cache_ram = 256
    server.start()

    prompt = "Look in thy glass and tell the face thou viewest. " * 15
    other = "The quick brown fox jumps over the lazy dog. " * 15
    lora = [{"id": 0, "scale": 0.5}]

    def complete(text: str, lora_cfg):
        data = {"prompt": text, "temperature": 0.0, "cache_prompt": True}
        if lora_cfg is not None:
            data["lora"] = lora_cfg
        res = server.make_request("POST", "/completion", data=data)
        assert res.status_code == 200
        return res.body

    first = complete(prompt, lora)
    complete(other, None)  # 1本しかないスロットから、最初の会話をRAMへ追い出す
    res = complete(prompt + "And then", lora)

    n_prompt = first["timings"]["prompt_n"]
    assert res["timings"]["cache_n"] >= n_prompt - 1

3つ目のリクエストの cache_n がどうなるかだけを見る。本番のGPUもモデルも要らず、テスト用の小さなモデルとCPUで再現できる。

	このテスト
本家（060b2fe）	落ちる（`cache_n = 0`、`prompt_n = 183`）
PR #30275を当てた版	通る

投稿から数日後、PRの作者から返信が来た。このテストを元にした回帰テストを 4e94dc5 で追加した、という内容だった。作者の環境でも、PRあり181トークン、ベースライン（1623d8c）0トークンで差が出たそうだ。

学んだこと

1. 「もっともらしい原因」は、外れ方で試す。 追い出しのログは本物で、容量説には筋が通っていた。「5分未満で外れる58回」は、それでは説明できなかった。

2. 割合を見たら、分母に何が混ざっているかを疑う。 42%と77%の比較には、当たるはずのないターンが入っていた。切り分けた27%と67%のほうが、バグの影響を正しく表している。

3. 黙って捨てる処理に、ログが無い。 判定の行はTRACEだけで、TRACEは利用者の本文まで出す。性能の不具合は例外を投げないので、まず見えるようにしないと始まらない。

4. 計測は、後で突き合わせずに済む形で残す。 サーバーのログとDBを時刻で合わせる推定には限界があった。今は呼び出しごとに、目的・セッション・LoRAの有無・再利用したトークン数を1行で残している。

5. 大きなOSSへの貢献はPRだけではない。 自分のPRは出ていないが、本番の症状と最小の再現テストは、既存のPRの検証を一段進められた。

まだ分かっていないこと

PR #30275はマージされていない。 レビューはこれからで、形が変わる可能性がある
このPR自体を本番では動かしていない。 本番は自前のforkで、同じ方針の別実装だ。PRで確かめたのはテストまで
LoRAなしの「会話の続き」で修正前に27%外れていた理由は、修正前のログに判定行が無いので特定できなかった
監視とLoRA、それぞれの修正単独の効果は分けられていない

数字はGLM-5.3-Flash 3bit、RTX PRO 6000 Blackwell ×2、4スロット、--kv-unified の環境のものだ。特に、GLM-5.3-Flashはキャッシュの途中で分岐すると巻き戻しにくいモデルなので、外れたときの重さはモデルによって変わる。

同じ症状かもしれない人へ

リクエスト単位で lora を指定していて、--cache-ram のRAMキャッシュを使っているなら、次の形が出ていないか見てほしい。

found better prompt で高い一致率のエントリを見つけているのに、直後のprefillが全トークンになる
LoRAありのリクエストだけ、スロットが入れ替わった後に外れる

上のテストをそのまま流せば、手元の版で起きるか確かめられる。