从 ASAN Stuck 到 Open Files Limit
<p><a href=https://github.com/google/sanitizers target=_blank rel="noopener noreffer" class=post-link>Sanitizers</a> 是好东西,可以帮助程序员检测错误并提供详细的错误报告。但前两天我遇到了一个问题,在我实验室主机的 Docker 容器中,AddressSanitizer 输出几行 Error 概述信息后,无法输出调用堆栈信息以及后续内容,程序会卡在这里,并且一个子进程会占满一个 CPU 核心。这件事我花了两天时间来排查,最终确定竟然是由于打开文件数限制设置太大导致的。请听我道来。</p><h2 id=发现问题><a href=#发现问题 class="header-mark headerLink">发现问题</a></h2><p>我准备了一个最小的 POC,用来重现本次事件的整个流程。以下是一个简单的 c 程序,如果直接编译运行会出现 SegmentFault,因为出现了越界写。</p><div class=highlight><div class=chroma><div class=table-wrapper><table class=lntable><tr><td class=lntd><pre tabindex=0 class=chroma><code><span class=lnt>1 </span><span class=lnt>2 </span><span class=lnt>3 </span><span class=lnt>4 </span></code></pre></td><td class=lntd><pre tabindex=0 class=chroma><code class=language-c data-lang=c><span class=line><span class=cl><span class=kt>void</span> <span class=nf>main</span><span class=p>()</span> <span class=p>{</span> </span></span><span class=line><span class=cl> <span class=kt>char</span> <span class=o>*</span><span class=n>str</span> <span class=o>=</span> <span class=s>"abc"</span><span class=p>;</span> </span></span><span class=line><span class=cl> <span class=n>str</span><span class=p>[</span><span class=mi>10</span><span class=p>]</span> <span class=o>=</span> <span class=sc>'z'</span><span class=p>;</span> </span></span><span class=line><span class=cl><span class=p>}</span> </span></span></code></pre></td></tr></table></div></div></div><p>使用 clang 编译并开启 AddressSanitizer: <code>clang -g -fsanitize=address -fno-omit-frame-pointer -o target_asan poc.c</code></p><p>正常情况下运行应该很快输出调用堆栈信息,如图:</p><p><figure><a class=lightgallery href=/posts/linux/large-nofile-cause-asan-stuck/asan_normal_works_hu843adcb9f4c3ef501072e5b1b984d972_142890_1243x1001_resize_q75_h2_box_3.webp title="AddressSanitizer 正常输出" data-thumbnail=/posts/linux/large-nofile-cause-asan-stuck/asan_normal_works_hu843adcb9f4c3ef501072e5b1b984d972_142890_1243x1001_resize_q75_h2_box_3.webp data-sub-html="<h2>AddressSanitizer 正常输出</h2><p>AddressSanitizer 正常输出</p>"><img src=/posts/linux/large-nofile-cause-asan-stuck/asan_normal_works_hu843adcb9f4c3ef501072e5b1b984d972_142890_1243x1001_resize_q75_h2_box_3.webp alt=/posts/linux/large-nofile-cause-asan-stuck/asan_normal_works_hu843adcb9f4c3ef501072e5b1b984d972_142890_1243x1001_resize_q75_h2_box_3.webp height=1001 width=1243 loading=lazy></a><figcaption class=image-caption>AddressSanitizer 正常输出</figcaption></figure></p><p>而这在我的 Docker 容器中就会卡住,通过 <code>top</code> 命令可以看到一个子进程占满一个 CPU 核心:</p><p><figure><a class=lightgallery href=/posts/linux/large-nofile-cause-asan-stuck/asan_stuck_hu6ff1142a74841c83d7167d84a2641030_34280_947x278_resize_q75_h2_box_3.webp title=卡住的情况 data-thumbnail=/posts/linux/large-nofile-cause-asan-stuck/asan_stuck_hu6ff1142a74841c83d7167d84a2641030_34280_947x278_resize_q75_h2_box_3.webp data-sub-html="<h2>卡住的情况</h2><p>卡住的情况</p>"><img src=/posts/linux/large-nofile-cause-asan-stuck/asan_stuck_hu6ff1142a74841c83d7167d84a2641030_34280_947x278_resize_q75_h2_box_3.webp alt=/posts/linux/large-nofile-cause-asan-stuck/asan_stuck_hu6ff1142a74841c83d7167d84a2641030_34280_947x278_resize_q75_h2_box_3.webp height=278 width=947 loading=lazy></a><figcaption class=image-caption>卡住的情况</figcaption></figure></p><p>我一开始以为程序就这样进入死循环了,谁知道等了几分钟竟然也输出了结果。</p><p>于是我开始查资料,在 <a href=https://clang.llvm.org/docs/AddressSanitizer.html#symbolizing-the-reports target=_blank rel="noopener noreffer" class=post-link>LLVM 文档</a> 中提到可以通过设置环境变量 <code>ASAN_OPTIONS=symbolize=0</code> 来关闭 symbolize 流程。实验发现关闭符号解析后可以顺利输出后续内容。</p><p><figure><a class=lightgallery href=/posts/linux/large-nofile-cause-asan-stuck/asan_options_symbolize_off_huad9cb65d0ed5337ff5eff9c1267928d2_70146_1247x311_resize_q75_h2_box_3.webp title="关闭 symbolize 可以顺利输出" data-thumbnail=/posts/linux/large-nofile-cause-asan-stuck/asan_options_symbolize_off_huad9cb65d0ed5337ff5eff9c1267928d2_70146_1247x311_resize_q75_h2_box_3.webp data-sub-html="<h2>关闭 symbolize 可以顺利输出</h2><p>关闭 symbolize 可以顺利输出</p>"><img src=/posts/linux/large-nofile-cause-asan-stuck/asan_options_symbolize_off_huad9cb65d0ed5337ff5eff9c1267928d2_70146_1247x311_resize_q75_h2_box_3.webp alt=/posts/linux/large-nofile-cause-asan-stuck/asan_options_symbolize_off_huad9cb65d0ed5337ff5eff9c1267928d2_70146_1247x311_resize_q75_h2_box_3.webp height=311 width=1247 loading=lazy></a><figcaption class=image-caption>关闭 symbolize 可以顺利输出</figcaption></figure></p><p>一开始我以为是符号解析器出 bug 了,尝试切换符号解析器,将默认的 <code>llvm-symbolizer</code> 替换成 GNU <code>addr2line</code>。</p><p><code>ASAN_SYMBOLIZER_PATH=/usr/bin/addr2line ./target_asan</code></p><p><figure><a class=lightgallery href=/posts/linux/large-nofile-cause-asan-stuck/addr2line_also_stuck_hu8684916663b9aea2101a5b0c731c9e79_37682_915x265_resize_q75_h2_box_3.webp title="addr2line 仍然会卡住" data-thumbnail=/posts/linux/large-nofile-cause-asan-stuck/addr2line_also_stuck_hu8684916663b9aea2101a5b0c731c9e79_37682_915x265_resize_q75_h2_box_3.webp data-sub-html="<h2>addr2line 仍然会卡住</h2><p>addr2line 仍然会卡住</p>"><img src=/posts/linux/large-nofile-cause-asan-stuck/addr2line_also_stuck_hu8684916663b9aea2101a5b0c731c9e79_37682_915x265_resize_q75_h2_box_3.webp alt=/posts/linux/large-nofile-cause-asan-stuck/addr2line_also_stuck_hu8684916663b9aea2101a5b0c731c9e79_37682_915x265_resize_q75_h2_box_3.webp height=265 width=915 loading=lazy></a><figcaption class=image-caption>addr2line 仍然会卡住</figcaption></figure></p><p>仍然卡住,于是我怀疑不是 <code>llvm-symbolizer</code> 的问题,感觉有可能是系统内核的问题,或者因为最新版 Docker 与内核冲突了?具体也不清楚,反正没有头绪。</p><p>当我把程序拷贝到宿主机上运行时,这个问题就莫名其妙的消失了。我将容器打包拷贝到同学的 Ubuntu 下,无法复现问题,也是顺利输出。我还尝试了将 Host 内核降级到 5.15,将 <code>Docker</code>/<code>Containerd</code>/<code>runc</code> 版本降级到与同学 Ubuntu 上相同的版本,均无法解决问题。</p><p>后面通过 strace 发现 AddressSanitizer 卡在 read 系统调用上,并通过上下文猜到与 <code>llvm-symbolizer</code> 交互的流程。</p><p><figure><a class=lightgallery href=/posts/linux/large-nofile-cause-asan-stuck/strace_stuck_in_read_hucfed7316ff0b1fed3a9a63b776d472d2_56014_907x471_resize_q75_h2_box_3.webp title="strace 发现卡 read 系统调用" data-thumbnail=/posts/linux/large-nofile-cause-asan-stuck/strace_stuck_in_read_hucfed7316ff0b1fed3a9a63b776d472d2_56014_907x471_resize_q75_h2_box_3.webp data-sub-html="<h2>strace 发现卡 read 系统调用</h2><p>strace 发现卡 read 系统调用</p>"><img src=/posts/linux/large-nofile-cause-asan-stuck/strace_stuck_in_read_hucfed7316ff0b1fed3a9a63b776d472d2_56014_907x471_resize_q75_h2_box_3.webp alt=/posts/linux/large-nofile-cause-asan-stuck/strace_stuck_in_read_hucfed7316ff0b1fed3a9a63b776d472d2_56014_907x471_resize_q75_h2_box_3.webp height=471 width=907 loading=lazy></a><figcaption class=image-caption>strace 发现卡 read 系统调用</figcaption></figure></p><p>这里可以看到 AddressSanitizer 通过 fork 子进程,然后通过 pipe 的方式与子进程通讯,写 <code>CODE "binary_path" offset\n</code> 来请求查询 <code>binary</code> 的 <code>offset</code> 位置对应的符号信息,如果查询成功会返回源代码、行号、函数名等符号信息。</p><p>我尝试手动运行 llvm-symbolizer,正常输出没有任何问题。</p><p>但是这个时候我是一筹莫展,睡觉前在 <a href=https://twitter.com/zu1k_/status/1668635289433292885 target=_blank rel="noopener noreffer" class=post-link>Twitter 上求助</a>,看看有没有人也遇到过这个问题。</p><h2 id=深入><a href=#深入 class="header-mark headerLink">深入</a></h2><p>根据网友 <a href=https://twitter.com/whsloef/status/1668636143863369729 target=_blank rel="noopener noreffer" class=post-link>whsloef 的回复</a>,我打印了阻塞的进程的调用栈,跟我通过 strace 得到的结论相同,是卡 read 系统调用了。</p><p><figure><a class=lightgallery href=/posts/linux/large-nofile-cause-asan-stuck/cat_stack_hu91b90d96476c14248a3c1870987a44bd_56594_1253x302_resize_q75_h2_box_3.webp title=打印调用栈 data-thumbnail=/posts/linux/large-nofile-cause-asan-stuck/cat_stack_hu91b90d96476c14248a3c1870987a44bd_56594_1253x302_resize_q75_h2_box_3.webp data-sub-html="<h2>打印调用栈</h2><p>打印调用栈</p>"><img src=/posts/linux/large-nofile-cause-asan-stuck/cat_stack_hu91b90d96476c14248a3c1870987a44bd_56594_1253x302_resize_q75_h2_box_3.webp alt=/posts/linux/large-nofile-cause-asan-stuck/cat_stack_hu91b90d96476c14248a3c1870987a44bd_56594_1253x302_resize_q75_h2_box_3.webp height=302 width=1253 loading=lazy></a><figcaption class=image-caption>打印调用栈</figcaption></figure></p><p>然后根据网友 <a href=https://twitter.com/JXQNHZr1yUAj5Be/status/1668684560195010561 target=_blank rel="noopener noreffer" class=post-link>Ningcong Chen 回复</a> 的一个历史 issue,我尝试用 gdb 来附加阻塞进程。(我之前考虑过给占用 100% 的进程做 profile,看看到底是什么行为占满 CPU,但考虑 AddressSanitizer 是 clang 注入的,不清楚好不好做,于是就没做)</p><p><figure><a class=lightgallery href=/posts/linux/large-nofile-cause-asan-stuck/gdb_attach_1_hu5fd188a493f98ec7189955c1da6cca08_6245292_2503x830_resize_q75_h2_box_3.webp title=附加主进程 data-thumbnail=/posts/linux/large-nofile-cause-asan-stuck/gdb_attach_1_hu5fd188a493f98ec7189955c1da6cca08_6245292_2503x830_resize_q75_h2_box_3.webp data-sub-html="<h2>附加主进程</h2><p>附加主进程</p>"><img src=/posts/linux/large-nofile-cause-asan-stuck/gdb_attach_1_hu5fd188a493f98ec7189955c1da6cca08_6245292_2503x830_resize_q75_h2_box_3.webp alt=/posts/linux/large-nofile-cause-asan-stuck/gdb_attach_1_hu5fd188a493f98ec7189955c1da6cca08_6245292_2503x830_resize_q75_h2_box_3.webp height=830 width=2503 loading=lazy></a><figcaption class=image-caption>附加主进程</figcaption></figure></p><p>附加主进程后,发现卡在 <code>internal_read</code>,推测是子进程没有返回。</p><p><figure><a class=lightgallery href=/posts/linux/large-nofile-cause-asan-stuck/gdb_attach_2_hu6d0f57975e98a16e3a64039d6dd5528d_257129_2384x791_resize_q75_h2_box_3.webp title=附加子进程 data-thumbnail=/posts/linux/large-nofile-cause-asan-stuck/gdb_attach_2_hu6d0f57975e98a16e3a64039d6dd5528d_257129_2384x791_resize_q75_h2_box_3.webp data-sub-html="<h2>附加子进程</h2><p>附加子进程</p>"><img src=/posts/linux/large-nofile-cause-asan-stuck/gdb_attach_2_hu6d0f57975e98a16e3a64039d6dd5528d_257129_2384x791_resize_q75_h2_box_3.webp alt=/posts/linux/large-nofile-cause-asan-stuck/gdb_attach_2_hu6d0f57975e98a16e3a64039d6dd5528d_257129_2384x791_resize_q75_h2_box_3.webp height=791 width=2384 loading=lazy></a><figcaption class=image-caption>附加子进程</figcaption></figure></p><p>附加子进程,发现卡在一个 for 循环上,通过调用栈信息,从 GitHub 上下载了源码,开始分析原因。</p><p>通过 LLVM compiler-rt 源码,定位到 <a href=https://github.com/llvm/llvm-project/blob/f9d0bf06319203a8cbb47d89c2f39d2c782f3887/compiler-rt/lib/sanitizer_common/sanitizer_posix_libcdep.cpp#L465 target=_blank rel="noopener noreffer" class=post-link><code>compiler-rt/lib/sanitizer_common/sanitizer_posix_libcdep.cpp#L465</code></a>,我把 <code>StartSubprocess</code> 简化为以下流程:</p><div class=highlight><div class=chroma><div class=table-wrapper><table class=lntable><tr><td class=lntd><pre tabindex=0 class=chroma><code><span class=lnt> 1 </span><span class=lnt> 2 </span><span class=lnt> 3 </span><span class=lnt> 4 </span><span class=lnt> 5 </span><span class=lnt> 6 </span><span class=lnt> 7 </span><span class=lnt> 8 </span><span class=lnt> 9 </span><span class=lnt>10 </span><span class=lnt>11 </span><span class=lnt>12 </span><span class=lnt>13 </span><span class=lnt>14 </span><span class=lnt>15 </span><span class=lnt>16 </span></code></pre></td><td class=lntd><pre tabindex=0 class=chroma><code class=language-cpp data-lang=cpp><span class=line><span class=cl><span class=n>pid_t</span> <span class=nf>StartSubprocess</span><span class=p>(</span><span class=k>const</span> <span class=kt>char</span> <span class=o>*</span><span class=n>program</span><span class=p>,</span> <span class=k>const</span> <span class=kt>char</span> <span class=o>*</span><span class=k>const</span> <span class=n>argv</span><span class=p>[],</span> </span></span><span class=line><span class=cl> <span class=k>const</span> <span class=kt>char</span> <span class=o>*</span><span class=k>const</span> <span class=n>envp</span><span class=p>[],</span> <span class=n>fd_t</span> <span class=n>stdin_fd</span><span class=p>,</span> <span class=n>fd_t</span> <span class=n>stdout_fd</span><span class=p>,</span> </span></span><span class=line><span class=cl> <span class=n>fd_t</span> <span class=n>stderr_fd</span><span class=p>)</span> <span class=p>{</span> </span></span><span class=line><span class=cl> </span></span><span class=line><span class=cl> <span class=kt>int</span> <span class=n>pid</span> <span class=o>=</span> <span class=n>internal_fork</span><span class=p>();</span> </span></span><span class=line><span class=cl> </span></span><span class=line><span class=cl> <span class=k>if</span> <span class=p>(</span><span class=n>pid</span> <span class=o>==</span> <span class=mi>0</span><span class=p>)</span> <span class=p>{</span> </span></span><span class=line><span class=cl> <span class=k>for</span> <span class=p>(</span><span class=kt>int</span> <span class=n>fd</span> <span class=o>=</span> <span class=n>sysconf</span><span class=p>(</span><span class=n>_SC_OPEN_MAX</span><span class=p>);</span> <span class=n>fd</span> <span class=o>></span> <span class=mi>2</span><span class=p>;</span> <span class=n>fd</span><span class=o>--</span><span class=p>)</span> <span class=n>internal_close</span><span class=p>(</span><span class=n>fd</span><span class=p>);</span> </span></span><span class=line><span class=cl> </span></span><span class=line><span class=cl> <span class=n>internal_execve</span><span class=p>(</span><span class=n>program</span><span class=p>,</span> <span class=k>const_cast</span><span class=o><</span><span class=kt>char</span> <span class=o>**></span><span class=p>(</span><span class=o>&</span><span class=n>argv</span><span class=p>[</span><span class=mi>0</span><span class=p>]),</span> </span></span><span class=line><span class=cl> <span class=k>const_cast</span><span class=o><</span><span class=kt>char</span> <span class=o>*</span><span class=k>const</span> <span class=o>*></span><span class=p>(</span><span class=n>envp</span><span class=p>));</span> </span></span><span class=line><span class=cl> <span class=n>internal__exit</span><span class=p>(</span><span class=mi>1</span><span class=p>);</span> </span></span><span class=line><span class=cl> <span class=p>}</span> </span></span><span class=line><span class=cl> </span></span><span class=line><span class=cl> <span class=k>return</span> <span class=n>pid</span><span class=p>;</span> </span></span><span class=line><span class=cl><span class=p>}</span> </span></span></code></pre></td></tr></table></div></div></div><p>这是一个典型的启动子进程的方法,先 <code>fork</code>,然后在子进程中关闭不必要的文件描述符,最后通过 <code>execve</code> 启动目标程序。</p><p>但 LLVM 这里通过 <code>int fd = sysconf(_SC_OPEN_MAX)</code> 获取最大文件打开数,然后循环关闭,在文件打开数限制很大的情况下就会进行很多不必要的系统调用,从而导致耗时又占 CPU,最终导致我出现我上面那种假死的情况,实际上进程正在忙着关闭不存在的文件描述符。</p><p>通过在容器内运行 <code>ulimit -n</code> 发现容器内的文件描述符限制是 <code>1073741816</code>,而对比宿主机的限制 <code>1024</code>,这种差异就是我将程序拷贝到宿主机就无法复线问题的重要原因。</p><p>我尝试在运行容器的时候加一个打开文件数限制 <code>--ulimit nofile=1024:1024</code>,问题顺利解决。</p><p>原来网友 <a href=https://twitter.com/lightning1141/status/1668726282811580416 target=_blank rel="noopener noreffer" class=post-link>lightning1141 的回复</a> 是让我看文件打开数是不是太大的意思啊,我还以为是看看够不够用呢。我之前一直以为这个东西设置的越大越好的,我 too naive too simple.</p><h2 id=思考><a href=#思考 class="header-mark headerLink">思考</a></h2><p>但既然宿主机限制是 <code>1024</code>,那为什么在 Docker 容器里的限制却有 <code>1073741816</code>?</p><p>我根据经验查询了以下文件,发现打开文件数均为默认,并未指定特定数值:</p><ul><li><code>/etc/security/limits.conf</code></li><li><code>/etc/systemd/system.conf</code></li><li><code>/etc/systemd/user.conf</code></li></ul><p>然后查看 docker 相关限制,因为由 systemd 管理,所以查看以下文件:</p><ul><li><code>/usr/lib/systemd/system/docker.service</code></li><li><code>/usr/lib/systemd/system/containerd.service</code></li></ul><p>在服务文件中均指定 <code>LimitNOFILE=infinity</code>,由此导致打开文件数不受限制,通过 <code>cat /proc/sys/fs/nr_open</code> 查看内核默认的进程打开文件数限制,发现是 <code>1073741816</code>。而在同学的 ubuntu 机器上 nr_open 是 <code>1048576</code>。</p><p>这种发行版的细微差别导致的问题真是难以排查啊!</p><h2 id=解决方案><a href=#解决方案 class="header-mark headerLink">解决方案</a></h2><h3 id=修改-containerd-文件描述符限制><a href=#修改-containerd-文件描述符限制 class="header-mark headerLink">修改 Containerd 文件描述符限制</a></h3><p>修改 <code>/usr/lib/systemd/system/containerd.service</code></p><div class=highlight><div class=chroma><div class=table-wrapper><table class=lntable><tr><td class=lntd><pre tabindex=0 class=chroma><code><span class=lnt>1 </span><span class=lnt>2 </span></code></pre></td><td class=lntd><pre tabindex=0 class=chroma><code class=language-fallback data-lang=fallback><span class=line><span class=cl>[Service] </span></span><span class=line><span class=cl>LimitNOFILE=1048576 </span></span></code></pre></td></tr></table></div></div></div><p>无需修改 <code>/usr/lib/systemd/system/docker.service</code></p><p>或者在启动容器的时候添加限制 <code>--ulimit nofile=1048576:1048576</code>:</p><p><code>docker run -it --ulimit nofile=1048576:1048576 ubuntu:18.04 /bin/bash</code></p><h3 id=修改-llvm-中逻辑><a href=#修改-llvm-中逻辑 class="header-mark headerLink">修改 LLVM 中逻辑</a></h3><p>可以修改 LLVM 源码,使用 <code>close_range</code> 或者 <code>closefrom</code> 系统调用替换 <code>close</code>.</p><ul><li><code>close_range</code> Linux kernel 5.9 增加, 在 BSD 也可用</li><li><code>closefrom</code> FreeBSD 8.0 引入, 在 Linux 上需要链接 <code>libbsd</code></li></ul><p>可惜的是这两个都不是 POSIX 规范定义的系统调用,不过我认为这后面会成为主流的。</p><p>只改了 <a href=https://github.com/zu1k/llvm-project/commit/ba3ac3c9e636b4f32590cda4f44ccf76cb84550d target=_blank rel="noopener noreffer" class=post-link>Linux 的版本</a>,并且需要 Kernel 5.9 以上。</p><h2 id=后续><a href=#后续 class="header-mark headerLink">后续</a></h2><p>在 GitHub 上相应仓库提起了 issue,等待改进。虽然自己改了一个 Linux 的可以用了,但是考虑到 LLVM 需要保证兼容性,这里也不敢去提 PR,毕竟要求 Linux 5.9 以上版本可不是一个兼容性好的方案。(我在 ubuntu 18.04 的 docker 里就没办法编译通过,<code>unistd.h</code> 里没有定义 <code>#define __NR_close_range 436</code>)</p><ul><li><a href=https://github.com/llvm/llvm-project/issues/63297 target=_blank rel="noopener noreffer" class=post-link>llvm/llvm-project/issues/63297</a></li><li><a href=https://github.com/google/sanitizers/issues/1662 target=_blank rel="noopener noreffer" class=post-link>google/sanitizers/issues/1662</a></li><li><a href=https://github.com/google/sanitizers/issues/1477 target=_blank rel="noopener noreffer" class=post-link>google/sanitizers/issues/1477</a></li></ul><blockquote><p>突然想到了一个之前别人问的一个问题:<a href=https://github.com/zu1k/blog/discussions/53#discussioncomment-4808529 target=_blank rel="noopener noreffer" class=post-link>当我运行 >500 个线程时代理开始失败</a></p><p>既然很多发行版单进程最大文件打开数是 1024,那这个问题就好推测了。这个代理程序对每一个连接需要打开两个文件描述符,一进一出嘛,那并发上不了 500,就是因为 1024 太小了。改一下就能解决。</p></blockquote>