使用 STRACE 排除 SUDO 运行缓慢问题

使用 STRACE 排除 SUDO 运行缓慢问题

我在某些系统上使用 sudo 时遇到了问题。完成 sudo 命令甚至登录系统都需要 15-30 秒的时间。

我运行了 strace,可以看到延迟发生在哪里,但我不确定哪里出了问题。它似乎在等待对 /dev/log 的写入请求?但这并没有告诉我太多信息,也没有告诉我为什么花了这么长时间。有没有 strace 专家可以更好地解释这一点?

12:08:21 munmap(0x7f5ccef9d000, 4096)   = 0
12:08:21 socket(PF_NETLINK, SOCK_RAW, 9) = 4
12:08:21 fcntl(4, F_SETFD, FD_CLOEXEC)  = 0
12:08:21 readlink("/proc/self/exe", "/usr/bin/sudo", 4096) = 13
12:08:21 sendto(4, "t\0\0\0M\4\5\0\2\0\0\0\0\0\0\0op=PAM:accountin"..., 116, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 116
12:08:21 poll([{fd=4, events=POLLIN}], 1, 500) = 1 ([{fd=4, revents=POLLIN}])
12:08:21 recvfrom(4, "$\0\0\0\2\0\0\0\2\0\0\0b3\0\0\0\0\0\0t\0\0\0M\4\5\0\2\0\0\0"..., 8988, MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 36
12:08:21 recvfrom(4, "$\0\0\0\2\0\0\0\2\0\0\0b3\0\0\0\0\0\0t\0\0\0M\4\5\0\2\0\0\0"..., 8988, MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 36
12:08:21 close(4)                       = 0
12:08:21 rt_sigaction(SIGTSTP, {SIG_IGN, [], SA_RESTORER|SA_RESTART, 0x7f5cce1de920}, NULL, 8) = 0
12:08:21 open("/var/db/sudo/matt/0", O_WRONLY|O_CREAT, 0600) = 4
12:08:21 fcntl(4, F_SETLKW, {type=F_WRLCK, whence=SEEK_CUR, start=0, len=0}) = 0
12:08:21 write(4, "\v\0\0\0\0\0\0\0\0\210\0\0\0\0\0\0\3\0\0\0\0\0\0\0`\206\212Q\0\0\0\0"..., 40) = 40
12:08:21 close(4)                       = 0
12:08:21 socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 4
12:08:21 connect(4, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
12:08:21 sendto(4, "<85>May  8 12:08:21 sudo:     ma"..., 95, MSG_NOSIGNAL, NULL, 0) = 95
12:08:34 close(4)                       = 0
12:08:34 close(3)                       = 0
12:08:34 munmap(0x7f5ccef9e000, 4096)   = 0
12:08:34 umask(022)                     = 02
12:08:34 umask(02)                      = 022
12:08:34 rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x7f5cce1de920}, NULL, 8) = 0
12:08:34 rt_sigaction(SIGQUIT, {SIG_DFL, [], SA_RESTORER, 0x7f5cce1de920}, NULL, 8) = 0
12:08:34 rt_sigaction(SIGTSTP, {SIG_DFL, [], SA_RESTORER, 0x7f5cce1de920}, NULL, 8) = 0
12:08:34 socket(PF_NETLINK, SOCK_RAW, 9) = 3
12:08:34 fcntl(3, F_SETFD, FD_CLOEXEC)  = 0
12:08:34 fcntl(3, F_SETFD, FD_CLOEXEC)  = 0
12:08:34 ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
12:08:34 readlink("/proc/self/fd/0", "/dev/pts/0"..., 31) = 10
12:08:34 lstat("/dev/pts/0", {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
12:08:34 getcwd("/home/matt", 4096)     = 11

答案1

您的问题是记录到系统日志的速度极其缓慢。

解释:

请注意 sendto 调用和 close 调用之间的 13 秒暂停:

12:08:21 connect(4, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
12:08:21 sendto(4, "<85>May  8 12:08:21 sudo:     ma"..., 95, MSG_NOSIGNAL, NULL, 0) = 95
12:08:34 close(4)  

sendto表示程序正在尝试发送一条消息。请注意,该消息看起来像一条日志行 ( May 8 12:08:21 sudo: ma)。它尝试将其发送到 fd 4。您可以在上方看到 fd 4 引用文件/dev/log。如果您发出命令,file /dev/log它将显示这是一个特殊文件 - UNIX 域套接字。如果您随后尝试,lsof /dev/log您将看到此套接字由 rsyslogd 守护程序保持打开状态。您可能已经猜到,此套接字用于接受其他程序的日志消息(它们连接到套接字并发送将被记录的消息)。因此,sudo 正在尝试通过 rsyslogd 记录一条消息,这需要很长时间。

通过查看 /etc/rsyslog.conf,您会发现延迟的原因是您将 rsyslog 配置为记录到没有响应的远程服务器。用户 @Alex North-Keys 指出有一些方法可以缓解此类问题(请参阅“故障转移日志到远程主机”https://wiki.archlinux.org/index.php/Syslog-ng

答案2

syslog-ng 有很多有用的选项可以缓解远程日志服务器死机的问题。请查看“故障转移日志到远程主机”https://wiki.archlinux.org/index.php/Syslog-ng

答案3

Rsyslog 远程已关闭。请参阅上面的评论。

相关内容