快杰云主机 SSH 登录缓慢的排查和解决 | U刻
技术分享/

快杰云主机 SSH 登录缓慢的排查和解决

  • 快杰云主机 SSH 登录缓慢的排查和解决

    快杰云主机是 UCloud 推出的具备优秀性能与极高性价比的新一代主机,网络最高可达 1000 万 PPS,存储最高可达 120 万 IOPS。为了提升产品综合表现,Host 内核、KVM 和 Guest 内核等做了大量调优。“高内核 Ubuntu18.04” 镜像就是其中一款经优化的云主机镜像,集成了官方 linux 5.0.1 主线版本内核。


    今年 7 月,有一位用户反馈,使用该镜像创建出的快杰云主机每次启动时,第一次 SSH 登录会很慢,有时候需几十秒甚至几分钟才能登录成功,影响了使用体验。


    经过排查,定位到是 Linux 内核随机数熵池初始化慢的原因,且在多个条件组合下才会触发。更深入调查则发现因为内核 bug,凡使用了 libssl 1.1.1 的进程(如开启了 https 的 nginx)都有类似问题,会对系统安全产生不少潜在影响。


    最终我们通过升级自主维护的内核,很快妥善修复了该问题,保证了快杰云主机的体验和安全性。

    本文对排查过程加以梳理。

    初步排查

    该问题只在单个用户上出现过,且只影响启动后的首次 SSH 登录,一旦登录成功便恢复正常。现场捕获不易,不过我们设法将其复现。
    ssh -v

    打开 ssh 用户端的冗余日志模式尝试登录问题主机,发现总是会卡在 “debug1: pledge: network” 处,根据提示,sshd 已经完成了用户的身份认证过程。


    可以看出,问题应当是发生在身份鉴定刚完成后,由此判断,问题有较大可能是发生在 /etc/pam.d/sshd 定义的 PAM 过程中。
    motd

    检视 /etc/pam.d/sshd 文件,根据现象以及直觉,决定尝试先屏蔽几段配置,其中就包括 motd 行,motd (message of the day) 是 Ubuntu 登录后呈现给用户看到的部分 banner 内容。随后重启主机,发现 ssh 登录变快,不再卡住。


    查阅资料可知,motd 机制下,pam_motd.so 会依次执行 /etc/update-motd.d/ 目录下的全部脚本,而这些脚本的输出则会被拼凑输出到文件 /run/motd.dynamic 中,最终呈现在 banner 中。


    因此,怀疑是这些脚本的执行过程中产生的卡顿,阅读这些脚本,执行断点 echo 调试,最后发现,位于”50-landscape-sysinfo”脚本中的 “/usr/bin/landscape-sysinfo” 命令执行时就会造成卡顿。


    landscape-sysinfo

    该命令仅仅是一个用来搜集显示 banner 中系统资源使用情况的工具,出现此问题有点难以置信,可实际上登录进入后多次执行此命令也没有出现卡顿。


    尝试进一步追踪此命令的执行,使用 strace 追踪此命令的执行,并记录日志。


    分析日志可以发现,启动时,该命令被卡在了 getrandom 系统调用上,解除阻塞时间点为 23:10:48。


    getrandom

    点击查看参考资料 http://man7.org/linux/man-pages/man2/getrandom.2.html

    getrandom 封装了对 /dev/urandom 字符设备文件的读取操作,用于获取高质量的随机数,/dev/urandom 会以 /dev/random 的值做为 seed 参考,/dev/random 值则来自硬件运行的噪音 (随机质量很高)。这种机制也决定了 /dev/urandom 在操作系统刚启动时生成的随机数质量不高(刚启动,/dev/random 中噪音不足,生成慢,随机性差,容易被预测,间接导致了 /dev/urandom 的起始 seed 质量低下),所以 /dev/urandom 内部对其质量设置了三种状态:

    • 0 = 未初始化,但是 /dev/urandom 已经可用;
    • 1 = 快速初始化,使用了少量熵数进行了快速初始化,在刚启动时就尽快可以被用起来,质量还行,但是仍然不被建议用于加密场景,通常发生在操作系统启动后的几秒内;
    • 2 = 完全初始化,随机数的质量达到最高,可以用于加密场景,操作系统启动后约几十秒 – 几分钟的时间才能达到。

    在默认情况下,getrandom 读取 /dev/urandom 前会去检测 /dev/urandom 的质量状态,如果尚未完全初始化,则会阻塞,直到其完全初始化,以此来保障通过此接口获得到的随机数质量高且速度快,为安全领域提供可靠的依赖。

    了解了 getrandom 接口的作用和表现后,再去翻看内核的启动日志,找到了时间相关性极高的点。


    可以看到,23:10:48 时 /dev/urandom 完全初始化后,随即 getrandom 的调用阻塞也被解除了,再多次重复验证后,关联性被确认。此时的结论以及建议解决办法为:原因:操作系统初始化随机数熵池速度较慢,导致 ssh 登录时使用到随机数的一条命令时被阻塞。
    建议:禁用 motd 或者删除 landscape-sysinfo 来达到加速 ssh 登录的目的。

    深入调查

    初步调查的结论有点违反常理,禁用或者删除的措施也需谨慎。为此,我决定找出更多的证据,此外,也需要解释为什么旧版本的 Ubuntu 并没有此现象。

    尝试查看表现正常的主机上 landscape-sysinfo 的 strace 表现,查阅日志后注意到,此环境下的 strace 记录与问题主机中 strace 记录在调用模式上存在不同,表现正常的主机上 landscape-sysinfo 中没有这样的调用 “getrandom (“xxx”, 32, 0) ”,注意第三个 flag 参数值,此 flag 用于表明使用 getrandom 的默认行为,即 /dev/urandom 未完全初始化时则阻塞。所有 getrandom 的地方都使用了 flag GRND_NONBLOCK,即如果没有初始化完成不要阻塞,返回错误就好。
    至此,怀疑是 landscape-sysinfo 版本问题。
    landscape-sysinfo

    对比两台主机上的 landscape-sysinfo 版本,发现版本号确实不同,有问题的版本号较高,没问题的版本号较低。

    将没问题的主机执行 apt-get update & apt-get upgrade,升级后发现问题果然重现。得出临时结论:landscape-sysinfo 新版本使用了 getrandom 的阻塞模式获取随机数,不要升级 landscape-sysinfo 的版本即可。
    开始尝试在其它主机上进行复现和验证,却发现,在另一个高内核版本的镜像中,低版本的 landscape-sysinfo 也能复现此问题,strace 追踪调用,发现其调用行为与高版本的 landscape-sysinfo 表现相似,鉴于此命令实际上是 python3 脚本,怀疑是其依赖的库升级导致。检查 apt-get upgrade 升级的 package,找出与随机数关联度较大的几个包,几次排除尝试后,定位发现,其实是由于 libssl1.1 这个库的升级导致的问题,getrandom 的调用也是源自于 libssl1.1。

    libssl1.1

    翻阅

    libssl1.1 的 release note https://www.openssl.org/news/openssl-1.1.1-notes.html


    可以看到,的确,libssl1.1.1 的升级,重写了内部随机数的生成器,也符合前面的表现,更新为使用 getrandom 读取更加安全的随机数(代价是刚开机时使用就容易被阻塞)。
    继续尝试在其它主机上进行复现和验证,又发现,在某个低内核版本的 Ubuntu 主机上,安装的正是 libssl1.1.1,却不能复现问题。按照预期,libssl1.1.1 的升级就是为了更安全,而如果一开机就能立刻得到随机数,这根本就违背的 getrandom 接口的设计初衷,此时倾向于怀疑内核可能存在 bug。
    内核 bug

    以 libssl 调用 getrandom 被阻塞为关键主题查阅资料,最终找到相关性较强的资料

    点击查看相关资料 https://unix.stackexchange.com/questions/442698/when-i-log-in-it-hangs-until-crng-init-done

    ,其中 CRNG 指密码学强度的随机数发生器。
    根据此资料,证实了内核 bug 的猜测,内核在 4.16 时修正过这样一个 bug:getrandom 在快速初始化完成后就不再阻塞,这与 getrandom 的接口设计违背,容易造成安全问题(CVE-2018-1108)

    内核 bug fix commit https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=43838a23a05fbd13e47d750d3dfd77001536dd33


    验证主机的内核版本为 4.15.0,与此情况符合,即很有可能是 bug 没有被修复,此时,开始尝试升级低内核版本主机的内核版本,如果此猜测正确,那么升级到高版本后应当同样会发生卡顿问题。
    在 apt 源上挑选了一个 5.0 版本的内核,升级后发现,居然也没有问题。
    翻阅内核日志,发现了一个新的现象,此前看到对于 /dev/urandom 的初始化,一般是会有一条 “fast init done” 日志,较长时间后会跟随一个 “crng init done” 日志,正好对应着 /dev/urandom 的两种质量状态。

    而此内核版本下,则是在刚启动就立即出现了 “crng done (trusting CPU’s manufacturer) ” 的日志,明显表明熵池被极速的初始化了,自然不会出现卡顿问题。


    查询此现象相关资料,找到了一个内核编译选项:CONFIG_RANDOM_TRUST_CPU。

    CONFIG_RANDOM_TRUST_CPU

    点此查看详细选项说明 https://lwn.net/Articles/760121/


    首次出现于 4.19 版本:https://cateee.net/lkddb/web-lkddb/RANDOM_TRUST_CPU.html

    检查高版本内核的两台主机,的确,有问题的主机此 flag 并没有 enable,无问题的主机此 flag 显式的 enable 了。

    而有问题主机使用的内核版本,取自于 Ubuntu 官方的最新主线分支编译,默认没有启动此 flag 做优化。
    结论

    此问题的出现需要同时满足以下几个条件:1. linux 内核版本在 4.17 及以上 2. linux 内核编译选项 CONFIG_RANDOM_TRUST_CPU is not set,或者 CPU 非 IVB 及以上的 x863. linux 内核 bug 未被社区 revert(4.x 的最新社区版本几乎都被 revert,5.x 没有 https://www.mail-archive.com/debian-bugs-dist@lists.debian.org/msg1602769.html)

    )4. libssl 版本在 1.1.1 及以上
    影响面

    事实上,SSH 登录卡顿仅仅是一种表象,这个问题的真实影响范围,可以扩展得非常大。凡是使用了 libssl1.1.1 来生成随机数的进程全都会受影响,导致重启后 3-5 分钟内会被随机数 block。比如,服务器上跑着 nginx(开启 https),一般认为机器启动后,nginx 马上启动就能提供服务了,但是受此问题影响,nginx 会被卡住三五分钟。就是说,前三五分钟内的用户 https 请求全部会出现访问失败的现象。
    问题修复

    为了做到性能与安全兼顾,在编译 4.19 及更高版本的内核时,启用 CONFIG_RANDOM_TRUST_CPU 选项,我们采用此方法,enable 选项并确保虚拟机可以访问 RDRAND 指令集,很快重新发布了云主机镜像。如果用户使用自定义内核,应尽量避开 4.17-4.19 之间的版本,或者妥善处理好 CVE-2018-1108。

    总结

    提起云主机,首先会想到计算、存储、网络,甚少有人关注内核。然而,内核构建也是云主机的核心工作,对性能和稳定性至关重要。

    SSH 登录缓慢起初是单一用户的反馈,且限于 Ubuntu 启动后的首次登录,但通过坚持排查和顺藤摸瓜,我们发现了潜在的影响面并予以修复,防患于未然。
    UCloud 团队通过自主维护云主机的内核源码,一方面可以不断调优性能来匹配产品的发展;另一方面保证了遇到现网各种问题时,有能力迅速排查和解决,并及时预防更大的系统安全风险。