追踪#

备注

--enable-tracing 要求 设置 --otlp-endpoint。如果启用追踪但没有 OTLP 端点,服务器将拒绝启动,因为没有本地回退用于追踪导出。

当启用追踪时(--enable-tracing --otlp-endpoint <URL>),追踪订阅者从 START/END 事件对创建 OTel spans:

  • mp.store — 从 MP_STORE_START 到 MP_STORE_END

  • mp.retrieve — 从 MP_RETRIEVE_START 到 MP_RETRIEVE_END

  • mp.lookup_prefetch — 从 MP_LOOKUP_PREFETCH_START 到 MP_LOOKUP_PREFETCH_END

每个 span 携带事件元数据作为 span 属性(例如 device、stored_count、found_count)。

在任何与 OTel 兼容的后端中查看追踪,例如 Jaeger 或 Grafana Tempo。

# Start Jaeger all-in-one (OTLP gRPC on 4317)
docker run -d --name jaeger \
    -p 16686:16686 -p 4317:4317 \
    jaegertracing/all-in-one:latest

# Start LMCache with tracing
lmcache server \
    --l1-size-gb 100 --eviction-policy LRU \
    --enable-tracing --otlp-endpoint http://localhost:4317

每个请求的命中率属性#

Each session is wrapped in a per-request root span — request for the standard MP path and cb.request for the CacheBlend path — that nests all child spans (mp.store, mp.retrieve, mp.lookup_prefetch) beneath it. When the lookup phase ends, the root span is annotated with OTel attributes that summarise the request-level cache hit rate. Both root spans carry the first three below; the rest are specific to the request span, and cb.request instead carries its own CacheBlend breakdown of hit_tokens (prefix / segmented-prefix / non-prefix).

属性

OTel 类型

描述

hit_tokens

int

从 L1+L2 命中并返回的 token 数(分子)。

requested_tokens

int

提交查找的块对齐 token 数(分母)。

hit_rate

float

hit_tokens / requested_tokens;当分母为零时取 0.0。以预计算浮点数形式存储,原因是追踪 UI(Tempo、Jaeger)无法在查询时从两个整数属性动态推导该值。

l1_hit_tokens

int

Tokens in the prefix L1 alone could serve, under each object group's attention window rule. request span only.

l2_hit_tokens

int

Tokens by which L2 extended that prefix. Together with l1_hit_tokens this is an exact integer partition of hit_tokens. request span only.

l1_hit_rate

float

l1_hit_tokens / requested_tokens; 0.0 when the denominator is zero. request span only.

l2_hit_rate

float

l2_hit_tokens / requested_tokens; 0.0 when the denominator is zero. Sums with l1_hit_rate to hit_rate up to float rounding. request span only.

l1_hit_keys

int

Hit keys (one per object group, kv rank and chunk) L1 already held. request span only.

l2_hit_keys

int

Hit keys loaded from L2. On hybrid models this can be small while l2_hit_tokens covers the whole hit (L2 supplied only the sliding-window keys). request span only.

early_exit_reason

str

Which branch of the lookup returned before a prefetch was submitted: no_gpu_context or no_group_layout_descs (nothing registered for this model / world size), or empty_chunk_hashes (prompt shorter than one chunk). "" on the normal path, including a genuine cold miss. request span only.

在处理 MP_LOOKUP_PREFETCH_END(标准 MP 路径)或 CB_LOOKUP_END(CacheBlend 路径)时写入这些属性——此时根 span 仍处于打开状态。纯存储请求不会调用 lookup_prefetch_start(),因此不会为查找阶段发出结束事件,其根 span 也不会携带这些属性。

示例 TraceQL 查询(Grafana Tempo):

# Requests with less than 50% cache hit rate
{ name = "request" && span.hit_rate < 0.5 }

# Full cache hits only
{ name = "request" && span.hit_rate = 1.0 }

# Complete misses (lookup ran but nothing was cached)
{ name = "request" && span.requested_tokens > 0 && span.hit_tokens = 0 }

# Requests that had to go to L2 for most of their hit
{ name = "request" && span.l2_hit_rate > 0.5 }

# Requests that loaded anything from L2
{ name = "request" && span.l2_hit_keys > 0 }

# Lookups that exited early rather than genuinely missing
{ name = "request" && span.early_exit_reason != "" }

有关完整的事件到 span 映射以及将子 span 关联回根 span 的注册模式,请参阅源码树中的 docs/design/observability/request-event-span.md。

追踪记录#

备注

追踪录制与 --enable-tracing(OTel span)是 两个独立的功能。追踪录制将每次 StorageManager 公共 API 调用记录到二进制文件,以便后续在无需 vLLM(最终也无需 GPU)的情况下 重放 相同的工作负载,用于测试、回归排查和基准测试。--enable-tracing 则将实时 OTel span 导出到 OTLP 端点以实现在线可观测性。两者相互独立,可同时使用。

当设置 --trace-level storage 时,LMCache 会将每次对 StorageManager.{reserve_write, finish_write, submit_prefetch_task, read_prefetched_results, finish_read_prefetched} 的调用记录到一个二进制文件中,以便后续重放。

录制默认关闭,关闭状态下开销几乎为零(每次 StorageManager 调用仅做一次布尔判断)。开启时,录制在 EventBus 排空线程上执行,不占用请求路径。

捕获追踪#

带有显式输出路径:

lmcache server \
    --l1-size-gb 100 --eviction-policy LRU \
    --trace-level storage --trace-output /tmp/run.lct

在 $TMPDIR 下使用隐式时间戳输出路径:

lmcache server \
    --l1-size-gb 100 --eviction-policy LRU \
    --trace-level storage
# → INFO log: "trace recording enabled (level=storage); no
#   --trace-output given, writing to
#   /tmp/lmcache-trace-<pid>-<UTC>.lct"

关闭时(SIGTERM 由 EventBus 停止路径处理),追踪文件会被正常关闭。

Capturing the cache-event stream#

--trace-level events records what this server would report to an MP coordinator: every cache-event batch (stores, deletes, accesses, capacity declarations) in the exact form POST /events carries. No coordinator is needed, so a fleet that runs without one can be captured and replayed later against a coordinator or a test double.

lmcache server \
    --l1-size-gb 100 --eviction-policy LRU \
    --trace-level events --trace-output /data/events-$(hostname).lct

One file is written per server; capture every server in the fleet. When --coordinator-url and --coordinator-event-reporting are also set, the same batches go to both the coordinator and the file. lmcache trace info prints instances, restarts, batches by type and tier, and bytes stored. Store entries carry the chunks' token ids, which are the prompt: treat the file as sensitive.

重放#

录制追踪的重放方式,以及驱动、监控和导出重放结果的完整 CLI 参数集,详见专属页面: 追踪和调试。

捕获了什么(以及未捕获的内容)#

捕获:

  • 每个被装饰的 StorageManager 方法调用的完全限定名(qualname)。

  • 每个调用的输入参数(例如 keys, layout_desc, mode, extra_count, external_request_id)。

  • 每个调用的墙钟时间和单调时间戳。

  • 包含追踪 schema 版本、开始时间以及当前 StorageManagerConfig 的 SHA-256 摘要的文件头,供重放时检测配置不匹配。

未捕获:

  • KV 张量的字节内容。重放仅演练状态记账与控制器逻辑;重放时的负载数据以零值填充。

  • MPCacheServer、消息队列或任何 GPU 拷贝代码内部的调用。这些层 不在存储追踪级别的采集范围内。

文件格式#

一个长度前缀的 msgpack 流:

[4-byte big-endian length][msgpack Header]
[4-byte big-endian length][msgpack Record]
[4-byte big-endian length][msgpack Record]
...

Header 包含魔数前缀(LMCT)、格式版本、追踪级别(当前为 storage)、追踪 schema 版本、开始时间戳以及 StorageManagerConfig 摘要。每个 Record 包含相对时间戳、墙钟时间戳、完全限定调用位置(qualname)和参数字典。

该格式有意设计为可扩展:未来的追踪 级别(mq、gpu)将共享此布局,并通过 level 头字段加以区分。新增捕获的操作只需添加新的 qualname 字符串,无需升级格式版本。

Transfer phase sub-spans#

With tracing enabled, each mp.store / mp.retrieve gets two child spans, one per GPU transfer phase:

  • transfer.kernel_interval -- gather/scatter kernel sections (paged KV blocks <-> GPU staging buffers). The name says interval because the kernel queues behind the co-resident inference engine's SM work: most of this bar is that wait, not the copy itself. Do not read it as a rate.

  • transfer.staging -- DMA copies (GPU staging buffers <-> pinned host memory) on the copy engine, which does not contend for SMs.

The two bars are a stacked breakdown, not a timeline: the phases alternate every batch step on one stream, so their real intervals interleave. The phase that ran first starts at the transfer's real start and lasts its total elapsed; the other follows for its own. Their sum is the transfer's stream time; the gap to the parent span is idle time.

Attributes: nbytes, elapsed_seconds, num_steps, the real first_start_s / last_end_s, device_index, session_id, and -- on transfer.staging only -- throughput_GB_per_second (nbytes / elapsed_seconds; see above for why the kernel span carries none). Timings are CUDA-event based, anchored to the same wall clock as the other MP events; the children are exported shortly after their parent.

有关完整的设计原理,请参见