问题描述
近期陆续碰到几台主机 df 卡住的问题, 监控程序由于超时引起相关的警报, 系统环境和 strace df 如下所示:
kernel-3.10.0-514.21.2 systemd-219-57
strace 显示卡在了 /proc/sys/fs/binfmt_misc 状态中:
# strace df
execve("/usr/bin/df", ["df"], [/* 29 vars */]) = 0
brk(0) = 0x1731000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa7720a7000
access("/etc/ld.so.preload", R_OK) = 0
open("/etc/ld.so.preload", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=24, ...}) = 0
......
stat("/sys/fs/cgroup/memory", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
stat("/sys/kernel/config", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
stat("/", {st_mode=S_IFDIR|0555, st_size=4096, ...}) = 0
stat("/proc/sys/fs/binfmt_misc",
在 systemd 服务中, 挂载 /proc/sys/fs/binfmt_misc
的只有两个 unit, 分别为 proc-sys-fs-binfmt_misc.automount
和 proc-sys-fs-binfmt_misc.mount
, 查看几台问题机器系统服务状态, 仅有 automount 服务启动:
proc-sys-fs-binfmt_misc.automount loaded active running Arbitrary Executable File Formats File System Automount Point proc-sys-fs-binfmt_misc.mount loaded inactive dead Arbitrary Executable File Formats File System systemd-binfmt.service loaded inactive dead Set Up Additional Binary Formats
问题机器分别进行过触发 mount 的操作, 但是没有进行过 systemctl stop proc-sys-fs-binfmt_misc.mount
操作:
May 30 17:34:53 cz1 systemd: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 292977 (sysctl) May 30 17:34:53 cz1 systemd: Mounting Arbitrary Executable File Formats File System... May 30 17:34:53 cz1 systemd: Mounted Arbitrary Executable File Formats File System. May 31 10:45:00 cz1 systemd: Unmounting Arbitrary Executable File Formats File System... May 31 10:45:00 cz1 systemd: Unmounted Arbitrary Executable File Formats File System.
查看snoopy 日志, unmount 操作由 pid 13573 进程操作, 该 pid 的 sid 为 1, pid 为 1 的进程为 /usr/lib/systemd/systemd --switched-root --system --deserialize 22
, snoopy 行为等同 automount 超时自动 unmount :
May 31 10:45:00 cz1 systemd[1]: Unmounting Arbitrary Executable File Formats File System... May 31 10:45:00 cz1 snoopy[13573]: [uid:0 sid:1 tty:(none) cwd:/ filename:/bin/umount]: /bin/umount /proc/sys/fs/binfmt_misc May 31 10:45:00 cz1 systemd[1]: Unmounted Arbitrary Executable File Formats File System.
问题机器的 mount 信息包含如下, timeout 为 300, 这个是 systemd-219-32
之前版本的默认参数, 实际上在 219-32
版本之前红帽还未引入超时功能, 所以超过 300s 之后 automount 不会自动进行 unmount 操作, 下面的内容仅有一条 binfmt 信息, 也意味着两台机器中没有访问 /proc/sys/fs/binfmt_misc 目录的行为:
systemd-1 /proc/sys/fs/binfmt_misc autofs rw,relatime,fd=30,pgrp=1,timeout=300,minproto=5,maxproto=5,direct 0 0
备注:问题主机由于在 yum 安装 perl 依赖的过程中更新了 systemd 到 219-57 新版, 但是没有做重启操作, 所以 mount 显示的 timeout 值还是 300, 重新 reload systemd 或 重启主机后新版 systemd 生效, timeout 值会变为默认 0.
automount 如何工作
systemd 通过 automount 实现了对文件系统挂载点进行自动挂载和控制的特性, 在用户访问指定目录的时候, 由 automount 判断自动进行挂载, nfs, sshfs 等使用较多, 目前为止在 centos7 系统中我们仅发现 binfmt_msic 类型是操作系统需要自动挂载的. 详见 systemd.automount
原因说明
从上述搜集信息来看, 更像是 systemd 认为 proc-sys-fs-binfmt_misc.mount
已经关闭, 不过系统或内核还持有 /proc/sys/fs/binfmt_misc
挂载点, 引起竞争, 这样 df 在访问挂载点的时候则一直处于挂起状态. 这个问题类似 nfs 服务端异常断掉, client 端直接访问挂载点也会挂起一样. 没有做超时处理则 df 一直处于等待状态.
详见: 1534701
触发条件
不过目前已知的触发条件包含以下两种方式:
第一种
人为制造异常:
1. 修改 proc-sys-fs-binfmt_misc.automount 的 TimeoutIdleSec 为大于 0 的值, 219-30 版本默认300, 不用修改; 2. 访问 /proc/sys/fs/binfmt_misc/ 目录触发 aumount 自动挂载; 3. 在1中还没有超时的时候执行 systemctl stop proc-sys-fs-binfmt_misc.mount, 手动 unmount 掉挂载点;
在执行第三步的时候 systemd 报以下异常, unmount 操作不能注册, 而系统内核会继续持有挂载点, 进而引起 df 卡住. 另外在默认 timeout 为 0 的情况下人为制造的异常不会引起 hang 住:
Jun 6 21:19:50 cz1 snoopy[162749]: [time_ms:357 login:root uid:0 pid:162749 ppid:162676 sid:162676 tty:/dev/pts/0 cwd:/root filename:/usr/bin/systemctl username:root]: systemctl stop proc-sys-fs-binfmt_misc.mount Jun 6 21:19:50 cz1 snoopy[162750]: [time_ms:359 login:root uid:0 pid:162750 ppid:162749 sid:162676 tty:/dev/pts/0 cwd:/root filename:/usr/bin/systemd-tty-ask-password-agent username:root]: /usr/bin/systemd-tty-ask-password-agent --watch Jun 6 21:19:50 cz1 snoopy[162751]: [time_ms:359 login:root uid:0 pid:162751 ppid:162749 sid:162676 tty:/dev/pts/0 cwd:/root filename:/usr/bin/pkttyagent username:root]: /usr/bin/pkttyagent --notify-fd 5 --fallback Jun 6 21:19:50 cz1 polkitd[1036]: Registered Authentication Agent for unix-process:162749:2586612889 (system bus name :1.232140 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) Jun 6 21:19:50 cz1 snoopy[162755]: [time_ms:371 login:(unknown) uid:0 pid:162755 ppid:1 sid:1 tty:(none) cwd:/ filename:/bin/umount username:root]: /bin/umount /proc/sys/fs/binfmt_misc Jun 6 21:19:50 cz1 polkitd[1036]: Unregistered Authentication Agent for unix-process:162749:2586612889 (system bus name :1.232140, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
执行 systemctl restart proc-sys-fs-binfmt_misc.automount
即可恢复所有堵住的命令. 另外在 TimeoutIdleSec 为 0 的情况下不会复现此问题, 在 TimeoutIdleSec 大于 0 的情况下, 给 systemd 发送 kill 信号的时候会导致 timeout 失效.
第二种
如下日志:
May 31 10:45:00 cz1 systemd[1]: Unmounting Arbitrary Executable File Formats File System... May 31 10:45:00 cz1 snoopy[6313]: [uid:0 sid:1 tty:(none) cwd:/ filename:/bin/umount]: /bin/umount /proc/sys/fs/binfmt_misc May 31 10:45:00 cz1 systemd[1]: Unmounted Arbitrary Executable File Formats File System.
我们以 snoopy 日志的 umount 操作为出发点, 在 systemd 源文件中查找对应行为的触发条件, 以 systemd-219-31
版本为例, 只有 mount_enter_unmounting
函数进行了 /bin/umount
操作, 详见 src/core/mount.c
文件:
static void mount_enter_unmounting(Mount *m) {
...
r = exec_command_set(m->control_command, "/bin/umount", m->where, NULL);
...
}
而 mount_enter_unmounting
函数仅被两个函数调用, 分别为正常 stop 操作的响应函数 mount_stop
和信号事件处理函数 mount_sigchld_event
:
...
#define RETRY_UMOUNT_MAX 32
...
static int mount_stop(Unit *u) {
...
mount_enter_unmounting(m);
return 1;
}
static void mount_sigchld_event(Unit *u, pid_t pid, int code, int status) {
...
MountResult f;
...
if (is_clean_exit(code, status, NULL))
f = MOUNT_SUCCESS;
else if (code == CLD_EXITED)
f = MOUNT_FAILURE_EXIT_CODE;
else if (code == CLD_KILLED)
f = MOUNT_FAILURE_SIGNAL;
else if (code == CLD_DUMPED)
f = MOUNT_FAILURE_CORE_DUMP;
else
assert_not_reached("Unknown code");
...
case MOUNT_UNMOUNTING:
case MOUNT_UNMOUNTING_SIGKILL:
case MOUNT_UNMOUNTING_SIGTERM:
if (f == MOUNT_SUCCESS) {
if (m->from_proc_self_mountinfo) {
/* Still a mount point? If so, let's
* try again. Most likely there were
* multiple mount points stacked on
* top of each other. Note that due to
* the io event priority logic we can
* be sure the new mountinfo is loaded
* before we process the SIGCHLD for
* the mount command. */
if (m->n_retry_umount id, "%s: mount still present, trying again.", u->id);
m->n_retry_umount++;
mount_enter_unmounting(m);
} else {
log_unit_debug(u->id, "%s: mount still present after %u attempts to unmount, giving up.", u->id, m->n_retry_umount);
mount_enter_mounted(m, f);
}
} else
mount_enter_dead(m, f);
问题主机的 umount 日志显示不是正常的 stop 操作, 从整个 systemd 日志来看 umount 操作更像是属于 mount_sigchld_event
函数的行为, 即在 systemd 的状态为 UNMOUNTING
, 或者收到 SIGKILL
, SIGTERM
信号的时候, 而系统或内核认为当前状态为 SUCCESS (f 变量), 在从 /etc/mtab
(mtab 为 /proc/self/mountinfo
的软链) 读取到 mount 信息的时候, 当前的重试次数(n_retry_umount) 小于 RETRY_UMOUNT_MAX (32) 的时候则进行一次 mount_enter_unmounting
函数调用. 不过问题主机上 df 等命令已经卡住了, 不能保证还会走到这个函数里, 另外也不明确什么情况下系统内核会和 systemd 的状态相反.
这种方式没有好的重现方法, 不过处理方式应该和第一种一样, 重启 proc-sys-fs-binfmt_misc.automount
即可.
解决方式
目前并没有找到真正的触发条件, 不过我们认为 df 卡住问题在本质上还是由于 systemd 和 kernel 之间存在竞争而引起的, 导致其它程序访问挂载点的时候出现 hang 住的现象, 根据 redhat bugzilla
的描述, 只要解决掉 mount 和 automount 过程中可能产生的竞争即可, 我们可以通过关闭 proc-sys-fs-binfmt_misc.automount
释放已经存在的竞争来解决 df hang 住的问题, 所以整体上包含以下三种解决方式:
1. systemctl restart proc-sys-fs-binfmt_misc.automount; 2. 升级到最新 systemd-219-57 版本; 3. 按照红帽知识库的步骤对 proc-sys-fs-binfmt_misc.automount 进行 mask 操作, 只进行静态的 mount 操作;
这几种方式对应用程序无害, 第一种方式影响最小. 不过我们在排错的过程中发现了一些其它相关的 bug, 所以采取第二种方式会更稳妥,新版的 systemd 对 1354410
和 1498318
两个 bug 做了状态反馈处理, 即便有问题也不会出现 hang 住的现象, 另外默认超时时间为 0, 对程序来讲相当于只做了重启操作, 不过后续的版本可能存在变更的可能, 所以保险起见可以将在 proc-sys-fs-binfmt_misc.automount
配置中指定 TimeoutIdleSec=0 参数值, 避免自动进行 unmount 操作. 最后重启机器即可; 第三种操作则可能影响其它有 automount 需求的软件(比如新版本的 postgresql), 不过很多软件在检测到没有启动 automount 的情况下会进行额外的 mount 操作, 不会有严重的影响.
参考链接:
红帽知识库
3346491
与我们的触发条件不一样, 并不是重新激活已经 mask 的 unit 问题引起的, 仅提供了类似问题的解决方法.
其它问题
在查找根源的过程中发现了几个相关的问题, 这些问题随 systemd 版本的变更进行了修复:
219-32 - automount: add expire support(TimeoutIdleSec) (#1354410) 219-46 - automount: if an automount unit is masked, don't react to activation anymore (#5445) (#1498318) 219-57 - BZ - 1498318 - du/df hang indefinitely (RHEL Atomic Host 7.4)
CoLaBug.com遵循[CC BY-SA 4.0]分享并保持客观立场，本站不承担此类作品侵权行为的直接责任及连带责任。您有版权、意见、投诉等问题，请通过[eMail]联系我们处理，如需商业授权请联系原作者/原网站。
