登录操作需要很长时间（系统日志问题）

Posted 2023-02-22

【中文标题】登录操作需要很长时间（系统日志问题）

【英文标题】：Login actions take so long (Syslog issue)

【发布时间】：2016-02-10 16:06:46

【问题描述】：

症状：

用户的每次登录操作（如 ssh、su、sudo 甚至退出）都需要将近一分钟的时间。

SSH 调用在这里很慢：

debug1: Authentication succeeded (publickey).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Requesting [e-mail]
debug1: Entering interactive session.

如果我这样做 strace -f su - juan ls 进程在这里很慢：

open("/etc/login.defs", O_RDONLY)       = 4
fstat(4, st_mode=S_IFREG|0644, st_size=10551, ...) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2c32202000
read(4, "#\n# /etc/login.defs - Configurat"..., 4096) = 4096
read(4, " issuing \n# the \"mesg y\" command"..., 4096) = 4096
read(4, " algorithm compatible with the o"..., 4096) = 2359
read(4, "", 4096)                       = 0
close(4)                                = 0
munmap(0x7f2c32202000, 4096)            = 0
sendto(3, "<86>Feb 10 17:36:33 su[4088]: + "..., 52, MSG_NOSIGNAL, NULL, 0

问题就在这里，当一个进程试图写入 /dev/log 时：

12:12:23 connect(1, sa_family=AF_LOCAL, sun_path="/dev/log", 110) = 0 <0.000008>
12:12:23 sendto(1, "<13>Feb 11 12:12:23 juan: hello "..., 37, MSG_NOSIGNAL, NULL, 0) = 37 <15.931766>

rsyslog的调试：

2042.323399028:7f5a60003700: --------imuxsock calling select, active file descriptors (max 4): 0 4 
2042.323419636:7f5a60003700: Message from UNIX socket: #0
2042.323434226:7f5a60003700: main Q: queue nearly full (10000 entries), but could not drop msg (iRet: 0, severity 6)
2042.323437267:7f5a60003700: main Q: doEnqSingleObject: queue FULL - waiting 2000ms to drain.
2044.323585582:7f5a60003700: main Q: doEnqSingleObject: cond timeout, dropping message!
2044.323616781:7f5a60003700: main Q: EnqueueMsg advised worker start

/var/log/syslog 和 /var/log/messages 为空

【参考方案1】：

正如您在问题中正确解释的那样，问题出在日志记录部分，您获得了一个用于 /dev/log 的套接字 (1)，然后使用它发送一条愚蠢的消息“hello juan”，但这需要 15 秒。

我在 vsftpd 上看到了同样的情况，它与服务本身无关，问题出在您的 rsyslog 上。如果你重新启动它，15 秒可能会减少到几乎为零，但它会随着时间的推移而增加。

此外，您的 rsyslog 队列几乎已满，这意味着您的远程服务器无法正常工作，或者您写入日志的磁盘非常慢，我猜是远程选项。

这是一条重要信息：

doEnqSingleObject: queue FULL - waiting 2000ms to drain.

由于我有自己的问题，所以我无法提供更多信息，但也许更改队列类型会有所帮助。

https://www.rsyslog.com/?s=queue

【参考方案2】：

这可能由于多种原因而发生，我建议开始调试的一个好地方是使用 -vvv 参数来输出正在发生的事情的更详细的跟踪，希望你能够发现它挂在进程的哪一部分

所以你的命令应该看起来像：ssh [e-mail] -vvv

【讨论】：

SSH 在这里停留一会儿：debug1: Authentication succeeded (publickey). ........... debug1: Requesting [e-mail] debug1: Entering interactive session.

它是挂在身份验证部分还是在进入交互式会话时？如果是 Auth 部分，那么我认为问题可能与 GSSAPI 有关，如果您不使用它，则可以通过将以下“GSSAPIAuthentication no”添加到 /etc/ssh/ssh_config

来禁用它

保存更改后，您还需要使用以下命令重新加载 ssh # service ssh reload 或者如果您使用的是 Fedora、RHEL 或 CentOS，我认为您需要使用# service sshd reload 而不是....区别是 sshd 而不是 ssh

看起来不像是 SSH 问题，任何登录操作都存在相同的错误，甚至是 su、sudo、exit……

不幸的是，我认为只有另外 2 件事可能是罪魁祸首，他们是 1. Sys log 守护进程行为异常 2. 反向 Dns 问题.....如果这些我会抓住稻草'不是问题，如果记录器'hello world'也需要很长时间才能响应，您可以测试守护程序是否有问题......通常如果是这种情况，只需使用“service rsyslog restart”重新启动Syslog，然后检查是否解决了这个问题。抱歉，我目前正在使用我的手机格式不佳

【参考方案3】：

确切地说，ssh 会话接受缓慢的问题可能有多种原因。这取决于您登录的用户是基于本地的还是基于 ldap 或 AD 的。 带有 -vvv 的 ssh 是检查具有最大调试日志级别的 ssh 的好选择，这将使您最好地了解它被挂起的位置。 请检查您尝试通过 traceroute 登录服务器的服务器之间的跃点数。

【讨论】：

不是 SSH 或网络问题，像 su 或 sudo 这样的本地操作很慢

它认为问题可能是由于 selinux 造成的。这里有一些更多信息：检查 /var/log/audit.log，如果发现一堆 avc 拒绝，直到最后放弃并让“su”继续。使用此链接获取更多信息 docs.redhat.com/docs/en-US/Re...ide/#id2839255 这表明 selinux 上下文对于不在 /home 中的主目录是错误的，这似乎是您目前的情况。

在写入 /dev/log 时看起来像一个问题