故障分析|ansible使用密码的一坑
背景
在做大批量运维的时候，DBA 需要掌握和使用 ansible。今天有同事使用 ansible 遇到了一个奇怪现象，和我交流了一下，我发现这个现象很奇怪，也很有趣，我认为是个 BUG，于是排查，之后有了这篇文章。
现象
同事使用的是ansible2.7.8，我使用的是最新版 python3.11+ ansible2.14，我们都复现了这个现象。这个问题简而言之是，使用比较特殊的密码组合作为主机密码，ansible 在使用上会遇到问题，导致正确的密码而无法连接。
以下是我的环境:
| 角色 | hostname | IP | 使用的密码 |
|---|---|---|---|
| ansible server | 192-168-199-121 | 192.168.199.121 | 不涉及 |
| 有问题的受控机 | 192-168-199-99 | 192.168.199.99 | 1#fander |
| 没问题的受控机 | 192-168-199-131 | 192.168.199.131 | Root-123 |
[root@192-168-199-121 ~]# cat /etc/ansible/hosts
[fander_vm]
192.168.199.99 ansible_user=root ansible_ssh_pass="1#fander"
[root@192-168-199-121 ~]# ansible 192.168.199.99 -m ping
192.168.199.99 | UNREACHABLE! => {
"changed": false,
"msg": "Invalid/incorrect password: Permission denied, please try again.",
"unreachable": true
}
同事疑问1——特殊密码，ansible无法连接会报错
同事设置了一个形如"1#xxxxxx"的密码，使用 ssh root@192.168.199.99 连接是完全没有问题的，但使用 ansible 连接则会报错，"Invalid/incorrect password: Permission denied, please try again." 无法连接。这个密码经过我的研究，是有规律，1位到任意长度的数字 + '#' + 任意长度字符，ansible 会报错。
也就是，以下密码会报错
1#fander 12#fander
以下密码不会报错
1a#fander 1@fander
同事疑问2——此特殊密码，ansible无法连接会报错，但有时却能连接不报错
排查过程
1. ansible -vvvvv 排查
-v参数可以让 ansible 输出 debug 日志，v 越多越详细。当然了，可能并不需要五个 v，我不知道要打多少个 v 时，我就把 v 打满。( mysqlbinlog 我打 3个 v )
如图红圈和横线，这两处很关键。
红圈告诉我，我在执行 ansible 时，其实底层调用的是 sshpass 和 ssh。
横线这一处，报有个文件不存在，我对比了执行正常连接的机器(192.168.199.131)，是不会报这个的，所以此处属于异常，需要排查。
这些日志输出其实一团糟，可以粘贴到 notepad++，用以下方法美化输出。
粘贴到 notepad++ 只有两行，通过替换 \r\n 为换行符即可。
首先，我先把 \r\n 替换为 fanderissb
然后，再以扩展模式，替换回来
现在就比较好阅读了，这一处就是不正常的。
经过研究，这些 debug 日志其实来源于我前面红圈的命令行 sshpass xxx 的输出。
查阅资料和整理，原理大概是这样的:
正确连接是长这个样子的，命令结果是输出"/root\n"，前面的 0 是命令 $? 的返回码，0 代表执行正常。
而我们密码有问题的服务器返回码是 5，输出是空
sshpass -d10 ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s \
-o StrictHostKeyChecking=no -o 'User="root"' -o ConnectTimeout=10 \
-o 'ControlPath="/root/.ansible/cp/e2f9f7759b"' 192.168.199.99 \
'/bin/sh -c '"'"'echo ~root && sleep 0'"'"''
在这句命令中，ControlPersist=60s 是 ssh 的参数，代表建立一个长链接，保持 60 秒，这个长链接就是建立在 ControlPath=/root/.ansible/cp/e2f9f7759b 的路径下。
实际上，就是这个 ControlPersist ，可以解答"同事疑问2——此特殊密码，ansible无法连接会报错，但有时却能连接"。
为了方便解释，我把 ansible 服务器的这个 ControlPersist 调大到 600 秒。
[root@192-168-199-121 ~]# cat /etc/ansible/ansible.cfg
[defaults]
host_key_checking = False
[ssh_connection]
ssh_args = -C -o ControlMaster=auto -o ControlPersist=600
首先，我登录远端服务器，先把密码改回常规密码。
[root@192-168-199-99 ~]# echo "Root-123"|passwd --stdin root
Changing password for user root.
passwd: all authentication tokens updated successfully.
接着，我配置好 ansible 服务器的 hosts 文件。
[root@192-168-199-121 ~]# cat /etc/ansible/hosts
[fander_vm]
192.168.199.99 ansible_user=root ansible_ssh_pass="Root-123"
然后，开始测试。完全没有问题，能连通。
[root@192-168-199-121 ~]# ansible 192.168.199.99 -m ping
192.168.199.99 | SUCCESS => {
"ansible_facts": {
"discovered_interpreter_python": "/usr/bin/python"
},
"changed": false,
"ping": "pong"
}
执行 ps -ef 能观察到，我们第一次连接完后，ssh 并没有断开，有一个背景执行的长链接，他实际上是一个多路复用的 socket 连接，后续我们再连远端服务器时就是复用他，不需要重新验证密码。
[root@192-168-199-121 ~]# ps -ef|grep ssh
root 860 1 0 17:18 ? 00:00:00 /usr/sbin/sshd -D
root 945 860 0 17:18 ? 00:00:04 sshd: root@pts/0,pts/1
root 9220 1 0 22:40 ? 00:00:00 ssh: /root/.ansible/cp/e2f9f7759b [mux]
root 9267 1009 0 22:41 pts/0 00:00:00 grep --color=auto ssh
这个时候，我把远端的服务器密码修改为有问题的密码
[root@192-168-199-99 ~]# echo "1#fander"|passwd --stdin root
Changing password for user root.
passwd: all authentication tokens updated successfully.
此时，我的 ansible 服务器的 hosts 配置里仍然用的旧密码
[root@192-168-199-121 ~]# cat /etc/ansible/hosts
[fander_vm]
192.168.199.99 ansible_user=root ansible_ssh_pass="Root-123"
密码是错误的，那么我还能连吗？答案是——能。这就是连接复用，不需要重新验证密码，直接复用前面的 socket 连接。
所以，这时你通过 ansible，密码乱输或者不输密码都能连。
[root@192-168-199-121 ~]# cat /etc/ansible/hosts
[fander_vm]
192.168.199.99 ansible_user=root #我这里直接去掉了密码
[root@192-168-199-121 ~]# date;ansible 192.168.199.99 -m shell -a "ls"
Sun Nov 13 22:49:15 CST 2022 #我复用这个链接的时间
192.168.199.99 | CHANGED | rc=0 >>
anaconda-ks.cfg
那么这个长链接是创建后的 600 秒自动销毁吗？(提醒，前面我修改的ControlPersist=600s)
答案——否。因为我在创建连接后，中途复用过这个连接通道，时间是 22:49:15，所以他消失时间不是创建时间 22:40:28 + 10 分钟，而是 22:49:15 + 10分钟，也就是 22:59:15。
[root@192-168-199-121 cp]# pwd
/root/.ansible/cp
[root@192-168-199-121 cp]# stat e2f9f7759b;date
File: ‘e2f9f7759b’
Size: 0 Blocks: 0 IO Block: 4096 socket
Device: fd00h/64768d Inode: 68415916 Links: 1
Access: (0600/srw-------) Uid: ( 0/ root) Gid: ( 0/ root)
Access: 2022-11-13 22:40:28.680577986 +0800
Modify: 2022-11-13 22:40:28.615577988 +0800
Change: 2022-11-13 22:40:28.615577988 +0800
Birth: -
Sun Nov 13 22:59:00 CST 2022
[root@192-168-199-121 cp]# stat e2f9f7759b;date
stat: cannot stat ‘e2f9f7759b’: No such file or directory
Sun Nov 13 22:59:30 CST 2022
# 超过22:59:15，socket消失了。
那同事的疑问2，就可以解释了，有问题的密码依然不能通过 ansible 连接，能连接的假象是因为曾经用正确的密码建立过长链接(这个是 ssh 的参数功能，不是 ansible)，后面连接时复用了此连接，没有使用密码认证，所以也就不会报错了。待ControlPersist 超时后，socket 销毁，有问题的密码连接就开始报错了。
我们继续排查同事的疑问1。
根据我前面整理的原理，我标记1、2、3、4数字的这几步，我按这个顺序从下往上开始一一排除。
其实，本来应该从最顶上的 4 开始排查的，但 4 需要阅读源码，所以我从简单的 1 开始排查。
2. 排查 ssh
首先，我测试标记为 1 的步骤，手敲这个密码，ssh 是否认正常。结果是连接正常。
3. 排查 sshpass
然后，测试标记为 2 的步骤，测试 sshpass 传输密码是否正常的。结果也是连接正常。
[root@192-168-199-99 ~]# sshpass -p "1#fander" ssh -C -o ControlMaster=auto -o ControlPersist=60s \
-o StrictHostKeyChecking=no -o 'User="root"' -o ConnectTimeout=10 \
-o 'ControlPath="/root/.ansible/cp/e2f9f7759b"' 192.168.199.99 \
'/bin/sh -c '"'"'echo ~root && sleep 0'"'"''
/root
这里，我调整了原命令，因为原命令用的是 sshpass -d10，这个文件描述符文件我不知道如何制造，所以我改为用 sshpass -p 来测试。我去掉了 -vvv ，因为如果一切正常，我不需要刷屏的 debug 日志。
4. 使用 paramiko 连接方式辅助排查
标记为 3 的步骤，我不知道如何测试，但我知道 ansible 除了 ssh 连接，还有一种叫 paramiko 的连接方式，他是旧版 ansible 的默认连接方式，他比较低效，他不使用 ControlPersist，也就不会建立 Control socket，而之前我们连接报错时，日志的关键信息就是Control socket "/root/.ansible/cp/e2f9f7759b" does not exist
当然了，他也不会使用 sshpass 和不会把密码写入那个数字为 10 的文件描述符。所以，如果我能在 paramiko 的连接方式能复现报错，那么就和标记为 3 的步骤无关。
[root@192-168-199-121 inventory]# cat /etc/ansible/ansible.cfg
[defaults]
host_key_checking = False
callback_whitelist = timer
transport = paramiko
结果是，我使用 paramiko 的连接方式，也能复现连接报错。
他这个 python 抛出异常非常好，终于让我知道为什么密码会错误了，原来传进去的密码不是"1#fander"，而是"1"。也就是问题肯定不在标记为 3 的步骤，而是标记为 4 的步骤。
根据报错，我在 auth_handler.py 文件里打了两个 print。
我们再看看输出。
那么，标记为 1、2、3 的步骤我们都排除了，问题出在标记为 4 的步骤，也就是现在的问题是：
为什么 ansible 传入给 sshpass 和 ssh 的密码不正确，应该传入"1#fander"，但最终传入"1" ？
5. 排查 ansible -k
我们再来做个测试，不使用 ansible hosts 文件传递密码，使用 -k 参数手敲密码。发现一切正常。
6. 水落石头，是 ansible 的 hosts 设置问题
那问题完全能定位出来了，这个疑似 bug，不是 ssh 也不是 sshpass 的问题，而是 ansible 的问题。并且，我们能确定，这个和 ansible 读取解析 /etc/ansible/hosts 文件有关。
经过我查阅资料，ansible 读取解析 /etc/ansible/hosts 相关的代码在这个路径下，ini.py 文件。
cd /usr/local/python3/lib/python3.11/site-packages/
cd ansible_core-2.14.0-py3.11.egg/ansible/plugins/inventory
less ini.py
通过阅读注释，发现这个不是 bug，而是官方知道的问题，所以属于一个坑。
最后
我经常阅读源码都是通过阅读注释就解决的，这很有趣，适合我这种萌新 coder。现在是 2022 年 11 月 13 日的 23:56 分，由于能力和时间的关系，我就写到这里了。大家应该看懂了解决办法，请大家避免这个坑，这个坑不单止针对密码，在 hosts 文件的所有变量设置都应该这么做(上图横线)。有兴趣深入研究的同学可以继续看看源代码。