日志记录#

日志订阅者通过 Python 的标准 logging 模块为存储、检索、查找、L1 和 StorageManager 事件发出调试级别的消息。

当安装 OpenTelemetry 时,init_logger 会自动附加一个 OTel LoggingHandler,以便将日志记录转发到任何配置的 OTel LoggerProvider。该处理程序遵循 LMCACHE_LOG_LEVEL 环境变量。

LMCACHE_LOG_LEVEL=DEBUG lmcache server ...

关键日志消息:

级别

消息

INFO

Stored N tokens in X seconds

INFO

Retrieved N tokens in X seconds

INFO

Prefetch request completed (L1+L2): N/M prefix hits

DEBUG

MP store start: session=... device=...

DEBUG

MP retrieve end: session=... retrieved_count=...

GC Monitoring (garbage-collection pauses)#

A full (generation-2) collection is stop-the-world and walks the whole heap, so it lands inside request handling as tail latency that nothing else in the server accounts for. Opt in to time collections and log the slow ones:

lmcache server ... --enable-gc-monitor --gc-monitor-min-pause-ms 10 --gc-monitor-top-objects 3
GC gen2 173.2ms collected=0 uncollectable=0 builtins.function=86911 builtins.tuple=70493 builtins.dict=45107

注意:

  • --gc-monitor-min-pause-ms (default 1.0) drops faster collections. 0 logs everything, including the sub-millisecond gen-0 sweeps CPython runs roughly every 700 net container allocations.

  • --gc-monitor-top-objects shows what the collector is walking, but scans the whole generation on every collection (O(heap), can itself cost hundreds of ms). Debugging only.

  • Non-zero uncollectable means CPython found garbage it could not free — a reference-cycle leak worth chasing.

  • The monitor logs directly instead of publishing events, so it is independent of the --disable-observability / --disable-metrics / --disable-logging flags.

额外日志记录(定期传输统计信息)#

选择性地记录周期性 INFO 级别的统计信息,旨在通过日志监控正在运行的服务器,而无需使用指标堆栈:

lmcache server ... --enable-extra-logging --extra-logging-interval 10

每个时间间隔,服务器日志 — 每个 GPU — 记录最后窗口的 L0<->L1 存取活动和自启动以来的累计总数(操作计数、令牌、大小(GB)和平均复制吞吐量(GB/s):

L0<->L1 stats [cuda:0] last 10.0s: store ops=12 tokens=24576 size=1.50GB avg_copy=12.34GB/s | retrieve ops=3 tokens=6144 size=0.40GB avg_copy=18.10GB/s
L0<->L1 stats [cuda:0] cumulative: store ops=120 tokens=245760 size=15.02GB avg_copy=12.10GB/s | retrieve ops=31 tokens=63488 size=4.11GB avg_copy=17.92GB/s

逐出循环还会在相同的时间间隔报告 L1 内存使用情况:

L1 memory usage: 45.20/100.00 GiB (45.2%)

注意:

  • 仅在有活动的窗口中发出传输状态行;L1 内存使用情况行在每个时间间隔内发出,无论负载如何。

  • avg_copy 仅测量 GPU 流复制时间的吞吐量(不是实际时间),当窗口内没有完成计时操作时显示 n/a

  • --extra-logging-interval 小于 1.0 的值受限于 1 Hz 的内部心跳。

  • --enable-extra-logging 即使在 --disable-logging 的情况下也能工作,但与 --disable-observability 冲突(服务器在启动时会引发 ValueError)。