有没有一种简单的方法来检查哪个程序写入/var/log/messages？

Question

有没有一种简单的方法来检查哪个程序写入了哪个文件？例如，我想检查哪个程序向 /var/log/messages 写入了错误。

Answer 1

TL; 博士

如果您只对确定哪个进程生成了给定消息感兴趣，请/var/log/messages查看每行的第一部分。这显示了进程名称以及生成给定行的 PID。在下面的示例中，fprintdPID 444 和gnome-sessionPID 8316 在我的messages日志中生成了这些行。

Feb 18 23:07:20 greeneggs fprintd[444]: ** Message: No devices in use, exit
Feb 18 23:08:53 greeneggs gnome-session[8316]: 23:08:53 | Git | personal_repo | Checking for remote changes...
Feb 18 23:08:53 greeneggs gnome-session[8316]: 23:08:53 | Cmd | personal_repo | git rev-parse HEAD

分析写入

进程不直接写入/var/log/messages，而是必须将消息发送到rsyslogd该消息，然后管理将消息写入该日志文件。如果您使用该lsof命令查看/var/log目录中的哪些文件被rsyslogd.

$ sudo lsof -p $(pgrep syslogd) | grep '/var/log'
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
rsyslogd 733 root    5w   REG              253,1 11413306    1323777 /var/log/messages
rsyslogd 733 root    6w   REG              253,1    61714    1318348 /var/log/cron
rsyslogd 733 root    7w   REG              253,1    60103    1323778 /var/log/secure
rsyslogd 733 root    8w   REG              253,1    49725    1323776 /var/log/maillog

我们可以用strace查看吗？

因此，一种方法是查看进程写入的内容rsyslogd，而不是messages直接查看日志文件。为此，我们首先必须确定所有rsyslogd线程的 PID 。

$ sudo ps -eLf | grep rsyslogd
root       733     1   733  0    4 Feb17 ?        00:00:00 /sbin/rsyslogd -n
root       733     1   795  0    4 Feb17 ?        00:00:01 /sbin/rsyslogd -n
root       733     1   796  0    4 Feb17 ?        00:00:00 /sbin/rsyslogd -n
root       733     1   798  0    4 Feb17 ?        00:00:01 /sbin/rsyslogd -n
root     27863 23659 27863  0    1 22:14 pts/2    00:00:00 grep --color=auto rsyslogd

有了手头的 PID，您可以strace用来观察日志写入rsyslogd. 这有点反复试验，但我能够使用strace这个 PID，然后logger用来模拟我的/var/log/messages日志文件上的活动。

例子

$ sudo strace -p 795 -s 2000 -o rsyslogd.log

现在我使用logger以下方法写一条消息：

$ logger hey

如果我们查看我们的strace日志文件，rsyslogd.log我们会看到这种类型的消息结果：

$ sudo tail -f rsyslogd.log
select(4, [3], NULL, NULL, NULL)        = 1 (in [3])
recvmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"<13>Feb 18 22:15:49 saml: hey", 8096}], msg_controllen=0, msg_flags=MSG_CTRUNC}, MSG_DONTWAIT) = 29
futex(0x7f41ba963d14, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f41ba963d10, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
futex(0x7f41ba963e70, FUTEX_WAKE_PRIVATE, 1) = 1
select(4, [3], NULL, NULL, NULL

如果我们strace所有rsyslogdPID，将它们的所有输出记录到不同的日志文件（me*.log其中 * = 1-4）然后tail -f me*.log，我们现在可以从我们的logger hey命令中获得扩展视图：

==> me1.log <==
)        = 1 (in [3])
recvmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"<13>Feb 18 22:23:23 saml: hey", 8096}], msg_controllen=0, msg_flags=MSG_CTRUNC}, MSG_DONTWAIT) = 29
futex(0x7f41ba963d14, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f41ba963d10, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1

==> me3.log <==
) = 0

==> me1.log <==
select(4, [3], NULL, NULL, NULL
==> me3.log <==
futex(0x7f41ba963e70, FUTEX_WAKE_PRIVATE, 1) = 0
write(5, "Feb 18 22:23:23 greeneggs saml: hey\n", 36) = 36
futex(0x7f41ba963d14, FUTEX_WAIT_PRIVATE, 67373, NULL

我们可以看到更多正在发生的事情，但我们仍然无法确定究竟是哪个进程向rsyslogd.

使用fatrace怎么样？

这是跟踪工具套件的新增功能，但在您的情况下证明非常有用。您可以使用此工具跟踪系统范围内的所有文件 I/O 访问，但我们可以将其重点缩小到仅/var/log目录，以查看是否无法找出向rsyslogd.

例子

对于初学者，我们将运行此命令来仅查看/var/log消息。

$ sudo fatrace | grep /var/log

现在当进程开始访问时，/var/log我们将得到一个稳定的流，知道哪个进程正在访问。

这是我运行此命令时的输出sudo -i：

systemd-journal(340): O /var/log/journal/0ee868f8b7da40f48013a281826b1b84
systemd-journal(340): C /var/log/journal/0ee868f8b7da40f48013a281826b1b84
rsyslogd(733): W /var/log/secure
rsyslogd(733): W /var/log/secure
auditd(546): W /var/log/audit/audit.log
auditd(546): W /var/log/audit/audit.log
auditd(546): W /var/log/audit/audit.log

下面是根ssh“通过本地主机荷兰国际集团入禁区，ssh root@localhost：

auditd(546): W /var/log/audit/audit.log
auditd(546): W /var/log/audit/audit.log
rsyslogd(733): W /var/log/messages
rsyslogd(733): W /var/log/messages
rsyslogd(733): W /var/log/secure
sshd(23718): O /var/log/lastlog
rsyslogd(733): W /var/log/secure
sshd(23718): RC /var/log/lastlog
sshd(23718): RCO /var/log/btmp
auditd(546): W /var/log/audit/audit.log
sshd(23724): RCO /var/log/lastlog
sshd(23724): O /var/log/wtmp
sshd(23724): W /var/log/wtmp
sshd(23724): W /var/log/wtmp
sshd(23724): CW /var/log/wtmp
sshd(23724): CW /var/log/wtmp
sshd(23724): CWO /var/log/lastlog
sshd(23724): CW /var/log/lastlog

因此，使用fatrace可以帮助您开始查明最终将日志消息驱动到/var/log/messages.

消息如何到达/var/log/messages？

如果你使用 SSH 之类的东西，守护进程sshd, 是由这个配置文件配置的，/etc/ssh/sshd_config. 该文件中有这一行指定sshd应将其日志文件消息发送到何处。

# Logging
# obsoletes QuietMode and FascistLogging
#SyslogFacility AUTH
SyslogFacility AUTHPRIV
#LogLevel INFO

所以这意味着它sshd正在使用SyslogFacility，并且它只发送AUTHPRIV或更高的消息。那么这些消息是如何到达的/var/log/messages呢？

看一下rsyslogd的配置文件，/etc/rsyslog.conf：

# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none                /var/log/messages

注意：注意authpriv左边的那个？这就是将消息“路由”sshd到文件/var/log/messages.

参考

• 确定负责高 I/O 的特定文件