今天花了几乎一天的时间排查一个 Ansible 连接异常断开的问题。翻遍了几乎所有的帖子都没有找到正确的答案,经过不断的尝试,终于把这个问题解决了,特此记录下来,期望能帮助到同样正在被这个问题折磨的人。
1. 问题描述
今天在网上花了 3.9 美金购买了一个 1U1G vps, 印象中 1U1G 的 vps 跑 linux 是没有问题的,所以就果断下单了。
由于 vps 是暴露在公网的,于是写了一个 Ansible playbook 用于加固 vps 的安全性,其中有一段是检查 firwalld package 有没有安装,内容如下:
1 2 3 4
| - name: Ensure firewall package is installed ansible.builtin.dnf: name: firewalld state: present
|
执行这一段的时候,死后就是报错,而且无论我如何折腾,都非常稳定地输出如下错误。
1 2 3 4
| TASK [security : Ensure firewall package is installed] ************************************************************* fatal: [remote_host]: FAILED! => {"changed": false, "module_stderr": "Shared connection to remote_host closed.\r\n", "module_stdout": "", "msg": "MODULE FAILURE\nSee stdout/stderr for the exact error", "rc": 137}
|
初看起来,非常像 SSH 连接超时,因此把整个 SSH 的工作原理,如何在服务器端,客户端,系统配置中调整 ssh 的参数研究了一遍。
而且试验了各种参数组合,都能正常 ssh 登陆远程主机,长时间不超时。但是当我运行 Ansible 脚本的时候依然如故。
2. 借鉴他人的解决方案
同时我也查找了网上类似的问题,以下这些文章是总结比较好的 How to Fix Shared connection to x.x.xx closed Ansible Error?。
How to Fix “Shared connection to x.x.xx closed” Ansible Error
这篇是 Ansible 官网的相关 issue.
ansible 排错,ansible_ts
这篇也遇到类似的问题, 只是类似, 根本原因(root cause)不一样,但是至今没有解答, 而且也走在错误的方向上,仍然考虑的是连接超时方向。
Ansible: “msg”: “MODULE FAILURE\nSee stdout/stderr for the exact error”
由于“Shared connection to remote_host closed.”是一个非常 general 的 error。受管机中的各种错误都可以导致 Ansible 管理机器抛出这个错误。
导致这个错误的原因,这里总结一下。
- 网络问题可以导致以上问题,解决办法是用 ssh 远程主机,查看具体错误,并针对性解决网络问题。
- 防火墙设置改变后,重新加载配置,可能导致连接中断。
- 受管机 Python 的 python 版本过低,可能导致连接中断。
- 受管机没有安装必要的软件可能导致连接中断。
实际情况远比以上总结复杂。
3. 误打误撞发现 root cause
尝试使用 vvvv 选项,看是否能获得有用信息。却又被引入了另外一个误区。
1 2 3
| ansible-playbook -vvvv -i hosts.ini security-enhancement.yml
|
1 2 3 4 5 6 7 8 9
| fatal: [remote_host]: FAILED! => { "changed": false, "module_stderr": "OpenSSH_9.6p1, OpenSSL 3.2.1 30 Jan 2024\r\ndebug1: Reading configuration data /home/eagle/.ssh/config\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug3: /etc/ssh/ssh_config line 55: Including file /etc/ssh/ssh_config.d/50-redhat.conf depth 0\r\ndebug1: Reading configuration data /etc/ssh/ssh_config.d/50-redhat.conf\r\ndebug2: checking match for 'final all' host remote_host originally remote_host\r\ndebug3: /etc/ssh/ssh_config.d/50-redhat.conf line 3: not matched 'final'\r\ndebug2: match not found\r\ndebug3: /etc/ssh/ssh_config.d/50-redhat.conf line 5: Including file /etc/crypto-policies/back-ends/openssh.config depth 1 (parse only)\r\ndebug1: Reading configuration data /etc/crypto-policies/back-ends/openssh.config\r\ndebug3: gss kex names ok: [gss-curve25519-sha256-,gss-nistp256-sha256-,gss-group14-sha256-,gss-group16-sha512-]\r\ndebug3: kex names ok: [curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512]\r\ndebug1: configuration requests final Match pass\r\ndebug2: resolve_canonicalize: hostname remote_host is address\r\ndebug1: re-parsing configuration\r\ndebug1: Reading configuration data /home/eagle/.ssh/config\r\ndebug2: add_identity_file: ignoring duplicate key ~/.ssh/id_rsa\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug3: /etc/ssh/ssh_config line 55: Including file /etc/ssh/ssh_config.d/50-redhat.conf depth 0\r\ndebug1: Reading configuration data /etc/ssh/ssh_config.d/50-redhat.conf\r\ndebug2: checking match for 'final all' host remote_host originally remote_host\r\ndebug3: /etc/ssh/ssh_config.d/50-redhat.conf line 3: matched 'final'\r\ndebug2: match found\r\ndebug3: /etc/ssh/ssh_config.d/50-redhat.conf line 5: Including file /etc/crypto-policies/back-ends/openssh.config depth 1\r\ndebug1: Reading configuration data /etc/crypto-policies/back-ends/openssh.config\r\ndebug3: gss kex names ok: [gss-curve25519-sha256-,gss-nistp256-sha256-,gss-group14-sha256-,gss-group16-sha512-]\r\ndebug3: kex names ok: [curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512]\r\ndebug3: expanded UserKnownHostsFile '~/.ssh/known_hosts' -> '/home/eagle/.ssh/known_hosts'\r\ndebug3: expanded UserKnownHostsFile '~/.ssh/known_hosts2' -> '/home/eagle/.ssh/known_hosts2'\r\ndebug1: auto-mux: Trying existing master at '/home/eagle/.ansible/cp/2389f72688'\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 14400\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet_timeout: read header failed: Broken pipe\r\ndebug2: Received exit status from master 137\r\nShared connection to remote_host closed.\r\n", "module_stdout": "", "msg": "MODULE FAILURE\nSee stdout/stderr for the exact error", "rc": 137 }
|
从详细日志里面,看到以下一行,非常可疑,但是却是一个误区, 通过查找 mux_client_read_packet_timeout 相关的资料,最后发现是只是一个 debug level 的信息。
1 2 3
| mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet_timeout: read header failed: Broken pipe
|
最后将重点放在了"rc": 137
,这行小字才是 root cause, 因为它是受管理机器上返回的唯一错误编号。其实中间我将重心放在超时问题时就已经注意到这行小字,由于这个数字太过抽象,实在没有引起重视。我也注意到很多相似问题,但是这个数字都不一样。
于是立马搜索了一下这个 137 代表什么样的错误。有相关问题提到 137 代表内存溢出,我也没想到是那里内存溢出。
因为中间有太多环节有可能内存溢出,有 Ansible 本身,有 ssh 的过程,有 python 解释器, 还有 dnf。后来我将 dnf 替换成 yum, 依然是一样的错误。
为了找到到底是哪个环节发生内存溢出。我在那里漫无目的的尝试,于是我登陆到远程主机,尝试 yum 命令,dnf 命令,这些命令只是打印出 Killed 消息,也没有与内存溢出产生联系。于是尝试在远程主机上使用不同版本的 sshd 服务,不同版本的操作系统。错误依然如故。心情异常沮丧。已经在考虑使用其他替代方案,手动写脚本来做安全增强了,但是手写脚本也得 dnf 或 yum 其中之一可用才可以呀。于是继续尝试。
不知道怎么想的,忽然在出现 killed 消息后执行了一下这条命令 echo $?
结果打印出了 137 这个错误代码,一下子就豁然开朗了。
1 2 3 4 5 6 7 8 9 10 11 12
| user@host ~ $ dnf search Python AlmaLinux 9 - AppStream 17 MB/s | 14 MB 00:00 AlmaLinux 9 - BaseOS 18 MB/s | 15 MB 00:00 AlmaLinux 9 - Extras 26 kB/s | 20 kB 00:00 Extra Packages for Enterprise Linux 9 - x86_64 19 MB/s | 23 MB 00:01 Killed user@host ~ $ yum search Python Killed user@host ~ $ echo $? 137
|
原来是受管机上的 dnf 和 yum 本身存在错误。137 是内存溢出。
但是查询了一下剩余内存,又还剩 500+M, 起初有些怀疑是不是 dnf 的问题, 还是 vps 的内存是虚标的。
1 2 3 4 5 6 7 8
| user@VM-6QOC7BH3 ~ $ free -h total used free shared buff/cache available Mem: 769Mi 212Mi 500Mi 3.0Mi 172Mi 556Mi Swap: 0B 0B 0B user@VM-6QOC7BH3 ~ $ sudo dnf update Killed
|
但是无论如何新买的机器 dnf 和 yum 都不能用那肯定得找管理员。于是提工单给 vps 管理说明情况,管理员立即给出回复。
1 2 3 4 5 6 7
| Hello This is because your process was killed due to insufficient memory. Please add swap or upgrade your package.
Best Regards, xxx
|
管理员,回复说是内存不足造成的,还是有些怀疑,于是把上面的可用内存发给他看,他又回了一句,建议添加 swap 分区然后重试。
1 2 3 4 5 6 7
| Hello We recommend that you add swap and then test again.
Best Regards, xxx
|
于是给 1U1G 的 vps 添加 swap 分区,添加 swap 分区的过程可以参考Linux 上添加 swap 分区
再次运行安全加固脚本,问题解决了。整个过程非常折磨人,在搜索解决方案的时候,也发现了很多人被这个问题折磨。
1 2 3
| ansible-playbook -vvvv -i hosts.ini security-enhancement.yml
|
4. 总结
这是由于 Ansible 报错不够清晰的原因导致的,中间多次被误导,被引入误区,虽然整个学习的过程受益匪浅,但是这种被折磨的感觉非常不爽。
所以一个清晰的报错信息,对软件的可用性非常重要,出现错误不可怕,可怕的是这种过于精简的报错信息。当然这不能全怪 Ansible,因为它拿到的错误代码就是这样。根本原因还在于 Linux, 或 Linux 的理念,很多编程语言错误返回就是一个代码,无论 python, shell, c, C++,一旦出处,排查问题折磨死人。
另外,Linux 的许多发行版本越来越臃肿了,对内存的要求都越来越高了,尤其是一个 dnf 和 yum 程序居然需要 500+M 的内存,确实是没有意识到的。我记得以前手里有一台非常老旧的笔记本,大概是零几年的还能跑 ubuntu, 一台树莓派还能跑 manjaro, 这种时代正在逐渐过去了。
就 Ansible 错误信息 “Shared connection to x.x.xx closed” 本身,需要第一时间将ansible-playbook -vvvv
打印出的实际运行脚本拿到受管机上去执行一下,尽快找到与"rc": xxx
对应的错误原因。只要找到原因,后续解决就比较有的放矢了。