查询循环：编译器谋杀之谜

# 查询循环：一则编译器谋杀悬案 来源: https://ferrous-systems.com/blog/query-cycles-a-compiler-murder-mystery/ 在 Ferrocene (https://ferrocene.dev/) 团队中，我们处理过许多棘手的问题，正如 Aïssata Maïga 在最近的 RustWeek 演讲《为 Rust 做认证的磨难》(https://www.youtube.com/watch?v=M5VPSUQF1q0&list=PL8Q1w7Ff68DBpmF38rcIAf8Z9Gj2TnlgM&index=29) 中所描述的那样。本文深入探讨了一个特别棘手的问题——它曾导致我的电脑崩溃，花了我一周多的时间来调试，最终发现是三个不同的 bug 组合在一起，产生了一个极其无用的错误信息。 ## 要是有个错误信息就好了…… Ferrocene 会定期合并上游 Rust 编译器中的变更。几个月前，我们在 CI 中遇到以下错误： ``` test [ui] tests/ui/delegation/bad-resolve.rs has been running for a long time [ui] tests/ui/delegation/bad-resolve.rs ... F test [ui] tests/ui/delegation/body-identity-glob.rs has been running for a long time Too long with no output (exceeded 20m0s): context deadline exceeded ``` 我在本地构建的编译器上查看了一下。我很多工作都是在“devpods”上完成的——它们与上游 Rust 项目的 dev-desktops (https://forge.rust-lang.org/infra/docs/dev-desktop.html#dev-desktops) 类似，但托管在 Ferrocene 的私有基础设施上，并使用了自定义 Docker 镜像，预先设置了许多构建依赖。与 dev-desktops 不同，它们是 Kubernetes pods，而不是完整的虚拟机。我喜欢它们，因为它们比我的本地 MacBook Air 快得多，而且可以直接运行 x86 架构，无需模拟。 我启动测试时没有遇到问题，然后去吃午饭，回来时看到了这个错误： ``` ci@devpod-pr-rotation-0 ~/ferrocene (automation/pull-upstream-HEAD/mscy1uah)> Connection to bastion.devpods.infra.ferrous-systems.net closed by remote host. client_loop: send disconnect: Broken pipe Connection to devpod-pr-rotation-jynn.ferrocene-devpods.svc.cluster.local closed by remote host. Connection to devpod-pr-rotation-jynn.ferrocene-devpods.svc.cluster.local closed. ``` 嗯，有点奇怪。我尝试重新连接： ``` $ ssh devpod-pr-rotation-jynn.ferrocene-devpods.svc.cluster.local -J bastion.devpods.infra.ferrous-systems.net channel 0: open failed: connect failed: Connection refused stdio forwarding failed Connection closed by UNKNOWN port 65535 ``` 这真的太奇怪了！这个错误通常出现在 `bastion` 容器内 DNS 解析失败时。这时我开始查看 devpod 的状态： ``` $ kubectl get pods devpod-pr-rotation-0 0/1 OOMKilled 0 16d ``` ……哦。好吧！显然这里出了大问题。我无法重启这个 pod；要恢复它，我必须运行 `kubectl --namespace ferrocene-devpods delete pod devpod-pr-rotation-0`，这会删除整个容器，包括磁盘上的数据。唉，一小时就这么没了。 ## 到底是什么触发了问题？ 我给自己建立了一个舒适的小开发循环： ``` $ git fetch origin eb655d5b3f940faf9b25749e84efed1b79944e98 && git checkout FETCH_HEAD # Create a build cache so we can set a reasonable timeout. $ ./x test tests/ui/diagnostic-width # `timeout` is to make sure that we don't immediately crash the devpod again. # `--no-capture` is to see output from RUSTC_LOG. # `--force-rerun` is to rerun the test even if neither the compiler nor the test have changed, # since compiletest doesn't count RUSTC_LOG as invalidating the cache. # `--keep-stage-std` is to avoid rebuilding the standard library when the compiler changes, # since none of our changes affect code that doesn't use delegation. $ timeout 10 ./x test tests/ui/delegations/bad-resolve.rs —-force-rerun --verbose --no-capture --keep-stage-std=1 ``` 并将崩溃最小化为以下 Rust 源代码： ``` #![feature(fn_delegation)] #![allow(incomplete_features)] trait Trait { type Type; fn bar() {} } struct F; impl Trait for F { type Type = i32; } struct S(F); impl Trait for S { reuse ::bar; } fn main() {} ``` 这里的 `reuse` 语法是未稳定的 `fn_delegation` 特性的一部分，rustc 指出它不完整且有 bug。在上游 rustc 中，这个程序会给出以下错误： （此处应有图片，但无法渲染） 在 Ferrocene 上，它会无限期挂起，没有任何输出。 首先，我尝试将调试日志级别调到最高： ``` { RUSTC_LOG=debug,rustc_middle::ty::print=info,rustc_span=info,rustc_parse=info \ timeout 5 rustc +ferrocene ./bad-resolve.rs || true } 2>&1 | less ``` 并在末尾得到了这样的输出： ``` 0ms DEBUG rustc_ast_lowering return=HirId(DefId(0:14 ~ bad_resolve[627f]::{impl#1}::bar).9) 0ms DEBUG rustc_middle::middle::codegen_fn_attrs::ferrocene parent=DefId(0:3 ~ bad_resolve[627f]::Trait), kind=Trait ``` 有希望！这个 `ferrocene` 模块是我们上周刚刚添加的；很可能还有一些 bug。我从一开始就怀疑这是某种无限递归，所以我拿出了 GDB。我处理无限递归的常用技巧是几秒钟后 Ctrl-C：即使你没有设置断点，GDB 在收到 SIGINT 时会自动进入交互式会话。 ``` $ gdb --quiet --args $(rustup which rustc --toolchain ferrocene) ./bad-resolve.rs Reading symbols from /home/ci/.rustup/toolchains/f1/bin/rustc... (gdb) run Starting program: /home/ci/ferrocene/build/x86_64-unknown-linux-gnu/stage1/bin/rustc bad-resolve.rs [New Thread 0x7fc650170700 (LWP 620169)] [New Thread 0x7fc64ff6f700 (LWP 620170)] [New Thread 0x7fc64f76b700 (LWP 620171)] ^C Thread 1 "rustc" received signal SIGINT, Interrupt. __pthread_clockjoin_ex (threadid=140489721837312, thread_return=0x0, clockid=<optimized out>, abstime=<optimized out>, block=<optimized out>) at pthread_join_common.c:145 145 pthread_join_common.c: No such file or directory. (gdb) info threads Id Target Id Frame * 1 Thread 0x7fc650179580 (LWP 620165) "rustc" __pthread_clockjoin_ex (threadid=140489721837312, thread_return=0x0, clockid=<optimized out>, abstime=<optimized out>, block=<optimized out>) at pthread_join_common.c:145 2 Thread 0x7fc650170700 (LWP 620169) "ctrl-c" futex_abstimed_wait_cancelable (private=0, abstime=0x0, clockid=0, expected=0, futex_word=0x7fc660b60498 <_RNvNtNtNtCsia3Q7nEBThM_5ctrlc8platform4unix14implementation9SEMAPHORE>) at ../sysdeps/nptl/futex-internal.h:320 3 Thread 0x7fc64ff6f700 (LWP 620170) "rustc" 0x00007fc65e63835f in new<(core::option::Option, rustc_middle::query::plumbing::ActiveKeyStatus)> () at /home/ci/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/hashbrown-0.16.1/src/raw/mod.rs:3584 4 Thread 0x7fc64f76b700 (LWP 620171) "rustc" syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:3 ``` 线程 1 只指向 `pthread_join_common.c` 中的 `pthread_clockjoin_ex`，这没有告诉我们太多信息。线程 3 看起来很有趣，让我们看看： ``` (gdb) backtrace #0 0x00007fc65e9b0e4c in {closure#0}<...> () at compiler/rustc_query_impl/src/execution.rs:74 #1 collect_active_query_jobs_inner<...> () at compiler/rustc_query_impl/src/execution.rs:93 #2 0x00007fc65ea89257 in {closure#108}<...> () at compiler/rustc_query_impl/src/execution.rs:56 #3 collect_active_query_jobs<...> () at compiler/rustc_query_impl/src/query_impl.rs:240 #4 0x00007fc65e9a9c19 in find_and_handle_cycle<...> () at compiler/rustc_query_impl/src/execution.rs:206 #5 0x00007fc65e932240 in try_execute_query<..., false> () at compiler/rustc_query_impl/src/execution.rs:333 #6 0x00007fc65e6773a8 in {closure#0}<...> () at compiler/rustc_query_impl/src/execution.rs:596 #7 maybe_grow<..., ...> () at /home/ci/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/stacker-0.1.21/src/lib.rs:57 #8 ensure_sufficient_stack<..., ...> () at compiler/rustc_data_structures/src/stack.rs:21 #9 execute_query_non_incr_inner<...> () at compiler/rustc_query_impl/src/execution.rs:596 #10 __rust_end_short_backtrace<...> () at compiler/rustc_query_impl/src/query_impl.rs:80 #11 0x00007fc65fd568c2 in query_get_at<...> () at compiler/rustc_middle/src/query/inner.rs:45 #12 def_span () at compiler/rustc_middle/src/query/plumbing.rs:571 #13 def_span () at compiler/rustc_middle/src/query/plumbing.rs:559 #14 default_span () at compiler/rustc_middle/src/query/keys.rs:141 #15 0x00007fc65fd5675e in _RNvXs7_NtNtCs4dSIRTpZwWb_12rustc_middle5query4keysNtNtCs8PBYVrj6O0O_10rustc_span6def_id10LocalDefIdNtB5_8QueryKey12default_span () at compiler/rustc_middle/src/query/keys.rs:129 #16 0x00007fc65fd83976 in default_span () at compiler/rustc_middle/src/query/plumbing.rs:447 #17 0x00007fc65e79c050 in create_cycle_error () at compiler/rustc_query_impl/src/job.rs:474 #18 0x00007fc65e9044de in _RINvNtCse5jIZt3jLA6_16rustc_query_impl9execution12handle_cycleINtNtNtCs4dSIRTpZwWb_12rustc_middle5query6caches10DefIdCacheINtNtB13_5erase10ErasedDataAhj8_EEEB4_ () at compiler/rustc_query_impl/src/execution.rs:117 #19 0x00007fc65e9a9c82 in find_and_handle_cycle<...> () at compiler/rustc_query_impl/src/execution.rs:209 ... #1048575 0x00007fcfee1dead in find_and_handle_cycle<...> () at compiler/rustc_query_impl/src/execution.rs:209 client_loop: send disconnect: Broken pipe ``` 哦，好吧。dev pod 又崩了。不过，我们还是在崩溃前得到了一些有用的信息！首先，超过一百万帧的调用栈简直荒谬至极。Linux 默认的栈大小限制是 8 MB： ``` $ ulimit --stack-size 8176 ``` 我通常见到的无限递归栈回溯有 2000 到 20000 帧，而不是……数百万帧。所以这里有什么地方不对劲。这很可能就是 GDB OOM 的原因。其次，这肯定是无限递归。存在一个周期为 15 的循环：`find_and_handle_query_cycle` -> `default_span` -> `def_span` -> `try_execute_query` -> `find_and_handle_query_cycle`。在第 8 帧处，有一个对 `ensure_sufficient_stack` (https://github.com/rust-lang/rust/blob/cf7da0b7277cad05b79f91b60c290aa08a17a6f0/compiler/rustc_data_structures/src/stack.rs#L20) 的调用。该函数的文档注释写道： > 按需增长栈以避免栈溢出。在战略位置调用此函数以“打破”递归调用…… 原来，当我们达到栈的极限时，编译器运行时就会检测到这一点，*将栈复制到堆上*，然后从堆上继续执行，从而获得更多栈空间。这让我们得到了那个荒谬的长回溯，直到因 OOM 而崩溃。 现在，介绍一些关于查询循环的背景知识。rustc 开发指南 (https://rustc-dev-guide.rust-lang.org/query.html) 对查询描述如下： > 编译器查询系统是 rustc 需求驱动（demand-driven）组织方式的关键。它不是完全独立的遍历阶段（解析、类型检查等），而是一组类似函数的 *查询*（queries）来计算关于输入源的信息。例如，有一个名为 `def_span` 的查询，给定某个条目的 `DefId` (https://doc.rust-lang.org/nightly/nightly-rustc/rustc_span/def_id/struct.DefId.html)，它会计算该条目源代码的 `Span` (https://doc.rust-lang.org/nightly/nightly-rustc/rustc_span/struct.Span.html) 并将其返回给你。 > > 查询的执行是 *记忆化*（memoized）的。第一次调用某个查询时，它会执行计算，但下一次，结果会从哈希表中返回。此外，查询执行非常适合 *增量计算*（incremental computation）；大致的想法是，当你调用一个查询时，结果*可能*通过从磁盘加载存储的数据返回给你。 Rustc 的查询系统将这种记忆化技术与一组精心设计的函数指针包装器结合在一起。Rust 没有头文件，因此到处插入函数指针使得所有查询可以在一处声明（目前是 `rustc_middle::queries`），但可以在工作空间的任何地方定义。1 (https://ferrous-systems.com/blog/query-cycles-a-compiler-murder-mystery/#fn:1) Rustc 将这些定义称为 **提供者（providers）**。例如，我们可以这样实现 `def_span`： ``` providers.queries.def_span = |tcx: TyCtxt, def_id: DefId| tcx.hir_span(tcx.local_def_id_to_hir_id(def_id)); ``` 查询可以调用其他查询。查询系统有一个运行时，可以动态跟踪查询之间的依赖关系，以确保在必要时重新运行，否则使用缓存。查询系统通过（query_name, arguments）元组来标识查询。只要参数不同，查询之间可以相互递归，就像普通函数递归一样： ``` providers.queries.hofstadter_m = |queries, n| if n == 0 { 0 } else { n - queries.hofstadter_f(queries.hofstadter_m(n-1)) }; providers.queries.hofstadter_f = |queries, n| if n == 0 { 1 } else { n - queries.hofstadter_m(queries.hofstadter_f(n-1)) } /* ... a whole bunch of setup ... */ assert_eq!(query_ctxt.hofstadter_m(5), 2); ``` 然而，如果查询名称和参数与同一调用栈中的先前调用相同，那就表明遇到了无限递归，这是一个 bug。查询系统称之为 **查询循环（query cycle）**。处理这个问题的函数叫做 `find_and_handle_cycle`，正常情况下它甚至会打印出诊断错误： （此处应有图片，但无法渲染） 因此，这里实际上有三个不同的 bug： 1. 编译器中某个地方，在 Ferrocene 中引入了查询循环，而上游 rustc 中没有。 2. 查询系统未能正确处理该查询循环，而是无限递归下去。 3. `ensure_sufficient_stack` 没有捕获无限递归；它没有栈保护 (https://www.usenix.org/legacy/publications/library/proceedings/sec98/full_papers/cowan/cowan.pdf)，并且会愉快地让你分配任意数量的内存。 我们先修复第 2 个问题。这样我们就能得到一个有用的诊断信息，告诉我们第 1 个问题是什么，就不必担心第 3 个问题了。 ## 找到凶器 我们在循环处理中看到的第一个帧是第 16 帧，`default_span`。该函数如下所示： ``` /// Returns the default span for this query if `span` is a dummy span. pub fn default_span(&self, tcx: TyCtxt<'tcx>, span: Span) -> Span { if !span.is_dummy() { return span } if let TaggedQueryKey::def_span(..) = self { // The `def_span` query is used to calculate `default_span`, // so exit to avoid infinite recursion. return DUMMY_SP } match self { $( TaggedQueryKey::$name(key) => $crate::query::QueryKey::default_span(key, tcx), )* } } ``` 这相当奇怪！查询系统的内部实现为了获取错误消息的 span，竟然*再次调用查询系统*。写这段代码的人知道无限递归的可能性并添加了一个检查，但不知何故这个检查没有触发，导致无限递归。我们应该在某个时候修复这个底层检查，但首先，我们至少先得到一个错误消息。我们可以通过总是返回一个 dummy span 来避免递归： ``` $ git diff -U0 diff --git a/compiler/rustc_middle/src/query/plumbing.rs b/compiler/rustc_middle/src/query/plumbing.rs index ef6259b1a0c..2efa5d82158 100644 --- a/compiler/rustc_middle/src/query/plumbing.rs +++ b/compiler/rustc_middle/src/query/plumbing.rs @@ -435,0 +436 @@ pub fn default_span(&self, tcx: TyCtxt<'tcx>, span: Span) -> Span { + return span; ``` 这样我们就得到了这个错误： （此处应有图片，但无法渲染） 这开始变得非常有帮助了。“codegen attributes”调用“entry function”看起来很眼熟，这难道不是我写的代码吗…… ……哦对，确实是我写的。 ``` /// Process the builtin attrs ([`hir::Attribute`]) on the item. /// Many of them directly translate to codegen attrs. fn process_builtin_attrs( tcx: TyCtxt<'_>, did: LocalDefId, attrs: &[Attribute], codegen_fn_attrs: &mut CodegenFnAttrs, ) -> InterestingAttributeDiagnosticSpans { // Ferrocene addition if let ValidatedStatus::Validated { .. } = item_is_validated(tcx, did.into()) { codegen_fn_attrs.validated = Some(Validated {}); } // ... } ``` `item_is_validated` 想判断某个条目是否是 `fn main`，这样它就可以将其视为你总是写了 `#[ferrocene::prevalidated]`。这段代码在上游并不存在，这就是为什么它只在 Ferrocene 中引起循环。为什么会导致循环呢？