1 问题现象
某天看 Ceph 监控,有个 CephFS 客户端持有了一千多万个文件的 capabilities,这不太正常。capabilities 是 CephFS 操作文件时需要的一个许可信息。官方解释:docs.ceph.com/en/nautilus…
2 问题分析
客户端持有 capabilities 时,会在 MDS(metadata server) 记录并占用内存。
为了防止占用太多内存导致 MDS 崩溃,有各种回收 caps 的设置,比如 mds_cache_memory_limit、mds_max_caps_per_client。
配置项 mds_max_caps_per_client,默认值为 1048576,但实际远大于这个设置,给 MDS 带来崩溃的危险。
Ceph 的每个 MDS 可以设置与其连接的客户端最多能拥有的 capabilities 数目。
查看 MDS 上客户端持有的 caps 数量,可以通过命令:ceph daemon mds.xxx session ls
查看 MDS 配置的 mds_max_caps_per_client:ceph daemon mds.xxx config show | grep caps_per_client
3 调查过程
接下来调查,为什么客户端持有的 caps 数量能够突破 mds_max_caps_per_client 的限制。
3.1 查看 CephFS kernel 客户端的 DEBUG 信息
环境中的 Ceph 版本是 nautilus v14.2.5,客户端机器内核是 v5.4.0。
登陆到问题客户端所在的机器,该机器通过 kernel 驱动的方式挂载 CephFS 目录。挂载方式的官方文档:docs.ceph.com/en/nautilus…
kernel client 会展示很多信息在 /sys/kernel/debug/ceph/ 目录下。官方介绍:docs.ceph.com/en/nautilus…
查看 caps 文件,确实里面有一千多万的 caps。
3.2 检查 caps 清理是否发生
当客户端持有的 capabilities 过多时,MDS 会发出释放 caps 的指令给客户端。
查看 linux kernel 源码,github.com/torvalds/li…
发现客户端在清理 caps 时,会调用 ceph_trim_caps 函数,输出 ”trim_caps mdsx start“ 字样的日志。
了解 linux dynamic_debug 功能后,打开了这个日志。
执行命令 echo -n 'func ceph_trim_caps +pflt' > /sys/kernel/debug/dynamic_debug/control,就可以在 /var/log/kern.log 中看到相关日志了。
Dec 21 20:52:01 xx kernel: [7973698.540182] [15905] ceph_trim_caps:1804: ceph: trim_caps mds4 start: 11272738 / 11267738, trim 5000
Dec 21 20:52:03 xx kernel: [7973700.278710] [15905] ceph_trim_caps:1804: ceph: trim_caps mds4 start: 11267738 / 11262738, trim 5000
Dec 21 20:52:05 xx kernel: [7973701.647546] [15905] ceph_trim_caps:1804: ceph: trim_caps mds4 start: 11284526 / 11279526, trim 5000
Dec 21 20:52:06 xx kernel: [7973703.051938] [15905] ceph_trim_caps:1804: ceph: trim_caps mds4 start: 11284381 / 11279381, trim 5000
从日志可以看出,caps 一直在清理,每隔几秒清理 5000 个。5000 这是数字是由 MDS 的配置 recall_max_caps 的默认值。尝试将这个值改大,但是 trim 的间隔时间变长了,没法加速清理。
所以 caps 一直清理,但总量一直不减少,应该是程序一直在申请 caps 导致的,和清理速度达到一个平衡。
3.3 找出增加的 caps 的程序
lsof CephFS 挂载目录会直接卡死很久。
尝试输出 ceph_add_cap 的日志,通过线程号找出相关程序,但是 ceph_add_cap 在内核中执行的。通过线程号找到的是 kworker。
[1633753.055305] [42217] ceph_add_cap:743: ceph: add_cap inode 000000001469df0e (200448027b8.fffffffffffffffe) cap 00000000bfa6b7db pAsLsXsFsx now pAsLsXsFsx seq 4 mds1
[1633753.064352] [42217] ceph_add_cap:622: ceph: add_cap 000000001469df0e mds1 cap 1f313ac72 pAsLsXsFsx seq 5
[1633753.064357] [42217] ceph_add_cap:727: ceph: issued pAsLsXsFsx, mds wanted AsLsXsFsx, actual p, queueing
[1633753.064363] [42217] ceph_add_cap:743: ceph: add_cap inode 000000001469df0e (200448027b8.fffffffffffffffe) cap 00000000bfa6b7db pAsLsXsFsx now pAsLsXsFsx seq 5 mds1
[1633753.073481] [42217] ceph_add_cap:622: ceph: add_cap 000000001469df0e mds1 cap 1f313ac72 pAsLsXsFsx seq 6
[1633753.073483] [42217] ceph_add_cap:727: ceph: issued pAsLsXsFsx, mds wanted AsLsXsFsx, actual p, queueing
又了解了 kernel tracing 和 vritual file system,准备从 ceph_readdir 这个函数入手找相关程序。
用户程序会调用 VFS,VFS 中遍历目录时,会调用 ceph_readdir ,内核代码: github.com/torvalds/li…
按文档 ftrace - Function Tracer — The Linux Kernel documentation 操作后,终于看到了用户的线程号。
# tracer: function
#
# entries-in-buffer/entries-written: 283/283 #P:48
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
find-3742 [045] .... 1634806.552342: ceph_readdir <-iterate_dir
find-3742 [045] .... 1634806.552831: ceph_readdir <-iterate_dir
find-3742 [045] .... 1634806.553158: ceph_readdir <-iterate_dir
find-3742 [045] .... 1634806.553167: ceph_readdir <-iterate_dir
find-3742 [045] .... 1634806.553226: ceph_readdir <-iterate_dir
find-3742 [045] .... 1634806.553233: ceph_readdir <-iterate_dir
(仅作示例,非当时场景)
通过这个方法,发现有用户把 TensorBoard 的观察目录设置到 CephFS 上一个有上千万子文件的目录,产生了大量 caps。
还有 ubuntu 自带的 mlocate package ,也会扫描 CephFS 目录,已有一些讨论 bugs.launchpad.net/ubuntu/+sou…
4 解决方法
告知用户把 TensorBoard 的观察目录设置范围小一些,问题就解决了。
但是这个行为用户自己是不知情的,不知道占用了大量全局资源,说不定之后启动了其他程序,大量扫描 CephFS 目录,申请大量 caps。如何限制用户行为保护系统稳定,并让操作的用户感知代价,避免这种行为?