debug-plan-cache-misses

调试 Chalk 查询计划缓存未命中

Chalk 首次规划查询时会缓存编译后的查询计划，缓存键由规范化后的 BatchQuery 组成。发生缓存未命中时，引擎必须在关键路径上重新规划，速度会很慢。首次遇到某种查询形态时，未命中是预期情况；但如果一个“看起来相同”的查询持续未命中，那就是个问题——这说明请求中的某个字段在不同调用之间发生了变化。

此技能会：（1）在日志中查找未命中；（2）对计划查询进行差异比较，准确找出导致未命中的不同字段。

缓存键的实际组成

计划缓存键会包装整个规范化后的 BatchQuery。唯一进行的规范化操作是将 planner_options 解析为其生效值，因此，不设置某个选项与将其显式设为默认值会产生相同的键，不会导致虚假的缓存未命中。

请求中的其他所有内容都是缓存键的一部分，包括：

• given_features——调用方提供的输入特征的确切集合
• 目标特征（optional_target_features / required_target_features）
• tags、required_resolver_tags
• max_staleness_overrides 以及陈旧度/重新计算标志
• query_name_and_version
• 以及其余 BatchQuery 字段

因此，这些字段中的任何差异都会触发新的计划。实际中最常见的原因是 given_features 集合发生变化——调用方有时会提供比之前调用更多或更少的输入特征（例如原始 *_original 输入，或 email_username 这类派生输入）。提供不同输入集合的查询确实需要不同的计划（必须运行不同的解析器），因此无法复用缓存的计划。

表明缓存未命中的两条日志

引擎会在规划路径上输出以下日志：

1. 即席查询未命中警告（batch_online_query_service.py）： Ad-hoc query request with query name/version '(<name>, <version>)' missed the plan cache. The query was: <BatchQuery ...>

2. 计划计算——每次未命中时都会输出（即席查询或命名查询均如此），是调试时最有用的一条日志（local_plan_factory.py）： Computed plan for [<target features>] given [<given features>] with planner options <NonNullPlannerOptions(...)>; query.query_name_and_version=(<name>, <version>)

如果想查看趋势而不是逐行阅读日志，也可以使用 statsd 计数器： chalk.engine.planner.python_plan_cache_miss 与 chalk.engine.planner.python_plan_cache_hit。

使用 chalk logs 查找未命中

chalk logs 会搜索环境的引擎日志。先指定正确的环境/上下文（使用 chalk config / 常用项目配置或 --environment 选择），然后按日志字段查询。

搜索过去一天的未命中警告：

chalk logs --query 'message:"missed the plan cache"' \
  --start-time "24h ago" --end-time "now"

搜索某个查询名称对应的计划计算日志（最适合进行差异比较）：

chalk logs --query 'message:"Computed plan for" message:sv5_idplus_features_parallel' \
  --start-time "24h ago" --end-time "now"

按 10 分钟的时间段统计未命中数量趋势：

chalk logs --aggregate --window-period 10m \
  --query 'message:"missed the plan cache"' --start-time "6h ago"

复现问题时实时跟踪未命中日志：

chalk logs --follow --query 'message:"missed the plan cache"'

查询语法

使用以空格分隔的 field:value 键值对（隐式 AND）。值中包含空格或 . 时需加引号，例如 message:"missed the plan cache"、query_name:"my.query"。可用字段：

• message——对日志消息进行子字符串匹配（对上面两条日志使用此字段）
• component——Chalk 组件，例如 component:engine
• query_name——筛选特定的命名查询
• operation_id——内部查询 ID；correlation_id——调用方提供的查询 ID
• trace_id、pod_name、resource_group、deployment、app
• all_filter——同时匹配多个字段

时间标志：--start-time / --end-time 接受 '1h ago'、'now' 或 ISO-8601 格式（'2024-01-01T00:00:00Z'）。添加 --tui 可使用交互式查看器。

调试工作流

1. 确认是否发生缓存未命中，以及发生频率：

   chalk logs --query 'message:"missed the plan cache"' --start-time "24h ago"
   

   如果这里没有内容，说明计划缓存正常工作——请从其他方面排查延迟。

2. 提取受影响查询名称对应的 Computed plan for 行：

   chalk logs --query 'message:"Computed plan for" message:<query_name>' \
     --start-time "24h ago"
   

3. 对比最近两次计算的每个字段：
   先比较 given [...] 列表（这是最常见的原因），然后比较目标特征列表，最后比较 planner options 块。任何差异都是未命中的原因。由于规划器选项在生成键之前会经过规范化，因此其中的差异是真实差异，而不是集合与默认值造成的表面差异。

4. 将差异归因于调用方。given 集合发生变化，几乎总是意味着上游服务发送的输入架构不一致（有时包含原始／派生输入，有时则不包含）。解决方法是让调用方在每次请求中都发送稳定的 given_features 集合，这样键就会保持稳定，后续相同的查询也能命中缓存。

说明

• 两个字节完全相同的请求，第二次调用时应该命中缓存。如果没有命中，这就不是字段不匹配的问题（例如缓存未填充或未共享），应单独说明，而不要归咎于请求。
• 只有所有调用方都采用同一种请求格式，修复未命中才会有效。如果仍有一些调用方发送不同的 given 集合，这些请求仍会未命中。
• 此技能会读取日志并分析请求，不会更改任何环境。任何补救措施（更改调用方发送的内容）都应在调用方的代码中实施，而不是在这里实施。