背景
某天,发现通过 ssh 登陆某台服务器的时候,发现需要等待很长的时间才能登录成功。
过程
一开始,以为是机器负载过高,导致加载 shell 的时候进程卡住,可是成功登录机器之后,发现服务器的 CPU、磁盘 IO 等均正常。然后怀疑是不是卡在了方向 DNS 查询的这一阶段,但是 UseDNS 这个配置是被这是为 no 的,这一个可能也被排除掉。 一时找不到具体的原因,就使用 debug 模式登录(-v 参数),发现卡在了 debug1: Entering interactive session 这个阶段,也就是说,密码输入正确之后,在加载 shell 的过程迟迟未能加载成功。后来,有发现,登录成功后,使用 su - xxx 命令切换用户时,也同样地会出现卡住很长一段时间,然后才成功切换的现象。灵机一动,想看看卡主的时候,进程在干些什么东西:
strace -f su - xxx
发现一直都卡在了 sendto 这个系统调用上:
... ...
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b89f4b000
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\3\0\0\0\3\0\0\0\0"..., 4096) = 405
lseek(3, -240, SEEK_CUR) = 165
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\3\0\0\0\3\0\0\0\0"..., 4096) = 240
close(3) = 0
munmap(0x7f9b89f4b000, 4096) = 0
socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 3
connect(3, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
sendto(3, "<86>Oct 30 22:55:56 su: pam_unix"..., 91, MSG_NOSIGNAL, NULL, 0) = 91
... ...
从上面的日志上可以看到,我们连接了 /dev/log 这个设备之后,通过 sendto 发型消息到 /dev/log 一直没有返回。上网查了下 /dev/log 这个文件的作用,发现它是跟 syslogd 进程相关的。任何一个进程如果将消息发送至 /dev/log,syslogd 便会将消息记录下来。由此联想到可能是 syslogd 进程出现问题了,后来重启 syslogd 之后,一切恢复正常。