使用日志文件
brimmer
原文：http://www.linuxpapers.org/show_article.html?LOG_FILES
翻译：Brimmer
“为了保证系统正常运行，为了解决每一天可能遇到的各种各样的问题，认真地读取日志文件是系统管理员的一项非常重要的任务。在这篇文章中，我将会解释什么是日志文件、在哪里可以找到日志文件以及如何处理它们” —— Gianluca Insolvibile
就算你只在家里使用Linux，迟早有一天你也会遇到一些奇怪的问题，如：PPP不能用了、X启动不了了，等等。这时候只能到日志文件中去寻找一些蛛丝马迹来解决问题。即使现在系统一切运行正常，作为系统管理员你也要对日志有所了解。否则，说不定哪一天……
系统日志文件
就象其它复杂的操作系统那样，Linux也是由很多不同的子系统组成的，每一个子系统完成一项特定的任务。例如，有些叫做daemon的程序一直在后台运行（也就是，他们“默默无闻”，不需要和用户交互），处理一些象打印、发送邮件、建立Internet连接，等等的日常工作。你看不到daemon程序，因为它们没有窗口和用户界面。但是，这些程序有时候也要给用户传递一些信息。为了实现这个目的，就需要一个特殊的机制。
Linux的内核是有很多子系统组成的，包括网络、文件访问、内存管理，等等。子系统需要给用户传送一些消息，这些消息内容包括消息的来源，重要性，等等。
这个问题的解决方案必须对内核或其它程序都是一致的，也就是所有的子系统都要把消息送到一个可以维护的公用消息区。于是，就有了一个叫syslogd的程序，这个程序负责接收消息并把消息分发到合适的地方。通常情况下，所有的消息都被拷贝（术语是“记录”（logged））到特定的文件（叫做“日志文件”，或简称“日志”（log））中，特别重要的消息也会在用户终端窗口上显示出来（请看图表1）。syslogd是daemon的一个很好的例子，它在后台运行并且把消息从日志区转移到日志文件中去。象大多数的daemon那样，它的名字也是用字母“d”作为结尾的。
日志文件通常是存放在“/var/log”目录下的。在Slackware 4.0的标准配置下，日志文件的文件名是messages、debug和syslog。请注意在Slackware发行版中有多种路径都可以到达“/var/log”目录，例如，“/var/adm”和“/usr/adm”都是指向“/var/log”的符号连接。在RedHat 6.0系统中可以发现有多个不同的日志文件，分别为：“/var/log/messages”、“/var/log/secure”、“/var/log/spooler”，等等。不同的Linux发行版的配置文件也有一些微小的差别，下面以Slackware为例，对于其它发行版，你可能需要做一些改动。
图表 1
查看日志文件
日志文件其实是纯文本的文件，每一行就是一个消息。只要是在Linux下能够处理纯文本的工具都能用来查看日志文件。简单地用cat命名就能把“/var/log/messages”文件中的消息显示到屏幕上，但是如果这个文件不只一页，那么就会因为显示滚动得太快看不清文件的内容。日志文件总是很大的，因为从你第一次启动Linux开始，消息都累积在日志文件中。待会儿，我回介绍如何限制日志文件的大小，但是请注意最好不要用cat显示日志文件的内容，最好也不要用文本编辑器打开日志文件，这是因为一方面很耗费内存，另一方面不允许随意改动日志文件。看日志文件的一个比较好的方法是用象more或less那样的分页显示程序，或者用grep查找特定的消息。我们先用less显示“/var/log/messages”。在图表二可以看到从日志文件中取出来的一些消息。每一行表示一个消息，而且都由四个域的固定格式组成：
l 时间标签（timestamp），表示消息发出的日期和时间
l 主机名（hostname）（在我们的例子中主机名为escher），表示生成消息的计算机的名字。如果只有一台计算机，主机名就可能没有必要了。但是，如果在网络环境中使用syslog，那么就可能要把不同主机的消息发送到一台服务器上集中处理。
l 生成消息的子系统的名字。可以是“kernel”，表示消息来自内核，或者是进程的名字，表示发出消息的程序的名字。在方括号里的是进程的PID。
l 消息（message），剩下的部分就是消息的内容了。
Sep 12 10:23:44 escher sendmail[85]: starting daemon (8.9.3): SMTP+queueing@00:15:00 ...
Sep 12 11:06:11 escher passwd[337]: password for `progs\ changed by `root\ ...
Sep 12 11:08:30 escher kernel: Disc change detected. ...
Sep 12 16:06:01 escher login[101]: ROOT LOGIN on `tty2\ ...
Sep 18 10:53:26 escher identd[251]: Connection from betelgeuse.branzo.it
Sep 18 10:53:26 escher identd[251]: from: 192.168.9.4 ( betelgeuse.branzo.it ) for: 1024, 21 ...
Sep 18 10:54:26 escher su[262]: + ttyp0 branzo-progs ...
Sep 18 11:17:12 escher -- MARK --
Sep 18 11:37:12 escher -- MARK --
Figure 2: Some logs extracted from /var/log/messages
图表 2
在我们的例子中，第一行是sendmail发出的消息，sendmail守护进程（daemon）负责管理收到和发出的消息。这一行是守护进程正常启动的消息。第二行是来自passwd的消息，提醒我们用户“progs”的口令被“root”改变过。以后其它的消息，报告我们系统的运行情况。实际上在“/var/log/message”文件中的消息都不是特别重要或紧急的。有一个很有趣的消息是“MARK”消息，在默认情况下每隔20分钟就会生成一次表示系统还在正常运行。“MARK”消息很象“心跳信号”（heartbeat），例如：“心跳信号”经常用来确认远程主机是否还在运行。“MARK”消息另外的一个用处是用作事后分析，能够帮助系统管理员确定系统死机发生的时间。
其它两个标准的日志文件是“/var/log/debug”和“/var/log/syslog”，这两个文件包含一些很重要的消息，例如：调试消息和错误提示。图表三是debug日志的一个例子。前面的几行是光盘被mount上一个SCSI设备（内核把它标识为sr(11,1)）时产生的信息而且被识别出来支持具有Joliet扩展的ISO 9660格式（也就是说这张光盘可能是由Windows程序创建的）。注意每一行的消息都包括生成这个消息的内核子系统的名字（VFS、ISO Extensions、ISOFS）。最后两行消息来自“sound”子系统，表示声音子系统初始化成功。
Sep 12 11:26:41 escher kernel: VFS: Disk change detected on device sr(11,1)
Sep 12 11:26:42 escher kernel: ISO 9660 Extensions: Microsoft Joliet Level 3
Sep 12 11:26:42 escher kernel: ISOFS: changing to secondary root ...
Sep 18 10:37:13 escher kernel: Sound initialization started
Sep 18 10:37:13 escher kernel: Sound initialization complete
Figure 3: Some logs extracted from /var/log/debug
图表 3
没有什么特殊的原因要把消息分成“debug”、“error”或者“normal”。因为产生这个消息的子系统为这个消息设置了一个类别，然后syslogd根据指示把消息分发到相应的文件中去。因此，尽管“sound”子系统的初始化消息属于别的消息类型，如果程序作者愿意还是可以决定把它设置成debug消息。待一会儿，我们会介绍如何准确地分类以及把不同类别的消息和相应的文件关联起来。
在继续介绍日志文件之前，请注意为了查看日志文件的内容必须要有“root”权限，因为日志文件中的信息对整个系统来说是很重要的，只能让超级用户有访问这些文件的权限。
日志文件是不断变大的
新的消息是加在日志文件的末尾的，因此最新的消息总是在文件的末尾出现。显示一个长文件末尾几行的一个方便的方法是使用带“-n”参数的tail命令。例如，为了显示messages日志文件的最后25行，可以用“tail –n 25 /var/log/messages”或“tail –25 /var/log/messages”。还有一个比较方便的方法是使用less，用“G”命令可以到达文件的末尾：运行“less /var/log/messages”，在退出程序之前按下“G”。用less最大的好处就是可以很方便地上下滚动文件和查找特定的字符串。
为了等待某个程序的某个特定的消息，可能要不断地查看日志文件。如果用不断地敲tail命令的方法直到消息出现为止，岂不是太麻烦了？在Linux系统中有一个很方便的方法，就是使用“tail –f /var/log/messages”命令。这个“tail”命令会显示日志文件的最后几行，但是不会马上退出。它会一直等到其它程序在指定的日志文件中加入消息行，并且马上就会把这些消息显示出来。“less”命令也可以用一个参数实现类似的功能，运行“less +F /var/log/messages”，这样就可以让less象“tail –f”那样运行。而且，less更容易交互使用，因为你可以在任何时候按“CTRL-C”退出等待消息并回到less的正常模式，然后滚动文件，查找字符串。
让我们用一个例子来说明：假定你想查看mount一个新的CDROM时产生的消息，而且这些消息发送到“/var/log/debug”文件中。把光盘放到光驱里，打开一个终端窗口，接着输入“tail –f /var/log/debug”命令（注意必须有“root”的权限）。然后，在另外一个终端窗口中用“mount /cdrom”或“mount /dev/cdrom”命令mount上光盘，查看第一个出现的信息。这些都很容易吧！请注意在RedHat 6.0中不能用上面的那些方法，因为在RedHat的标准配置中并不记录debug消息。但是，如果接着读下去，你就可以学会改变配置文件。
配置日志
让我们仔细地研究一下syslogd守护进程的运行情况。我们曾经说过这个程序是在后台运行，从系统中获取新的消息，并把消息发送到合适的地方。我们先看看syslogd可以处理哪些类型的消息。请记住每一个子系统发出日志消息的时候都会给消息指定一个类型。说得更准确一点，一个消息可以分成两个部分：“设备”和“优先级”。“设备”标识发出消息的子系统，“优先级”表示消息的重要性，其范围从7（最不重要）到0（最重要）。图表4和图表5是“/usr/include/sys/syslog.h”文件的一部分，在这两个图表中可以看到内核2.2.6版本中定义的所有“优先级”和“设备”。
Definition Value Comment
LOG_EMERG 0 /* system is unusable */
LOG_ALERT 1 /* action must be taken immediately */
LOG_CRIT 2 /* critical conditions */
LOG_ERR 3 /* error conditions */
LOG_WARNING 4 /* warning conditions */
LOG_NOTICE 5 /* normal but significant condition */
LOG_INFO 6 /* informational */
LOG_DEBUG 7 /* debug-level messages */
Figure 4: Message Priorities
图表 4
Definition Syslog Name Comment
LOG_KERN Kern /* kernel messages */
LOG_USER User /* random user-level messages */
LOG_MAIL Mail /* mail system */
LOG_DAEMON Daemon /* system daemons */
LOG_AUTH auth,security /* security/authorization messages */
LOG_SYSLOG Syslog /* messages generated internally by syslogd */
LOG_LPR Lpr /* line printer subsystem */
LOG_NEWS News /* network news subsystem */
LOG_UUCP Uucp /* UUCP subsystem */
LOG_CRON Cron /* clock daemon */
LOG_AUTHPRIV authpriv /* security/authorization messages (private) */
Figure 5: Message Facilities
图表 5
你必须知道的第二件事是如何配置syslogd。基本的配置是很简单的，但是一些高级特性的配置需要一些经验。我们现在看看基本的配置，也就是根据“设备”和“优先级”哪些文件应该收到哪些消息。可以通过编辑编辑文件（通常是“/etc/syslog.conf”）可以对任务进行定制。在开始之前，我们先用less命令看看“/etc/syslog.conf”文件。在图表6中可以看到在Slackware 4.0中命令运行的结果。以“#”号开头的行都是注释行。其它的一些行也很容易理解，他们是由两个域组成，分别是“选择器”（selector）和“动作”（action）。“选择器”用相应的“设备”和“优先级”（都可以用“*”通配符表示“任何一个”）来表示消息的类型。“动作”表示一旦有一个新的消息和“选择器”相匹配的时候要采取什么行动。如果“动作”只是一个文件名（刚安装好的系统一般都是这样的），那么消息就会被添加到这个文件中。
# /etc/syslog.conf # For info about the format of this file, see \"man
syslog.conf\" (the BSD man # page), and /usr/doc/sysklogd/README.linux.*.=info;*.=notice
/usr/adm/messages *.=debug /usr/adm/debug*.err /usr/adm/syslog
Figure 6: Contents of /etc/syslog.conf
图表 6
如果你看看图表6，就会发现“优先级”等于“info”和“notice”的消息，无论他们的“设备”是什么，都发到“/usr/adm/messages”文件，因为在“选择器”中使用了通配符。同样“优先级”为“debug”和“err”的消息都分别送到“/usr/adm/debug”和“/usr/adm/syslog”文件。刚安装好的RedHat系统没有处理“debug”消息的那一行，在“syslog.conf”文件中可以加入这一行，这样就可以正常使用上面介绍的例子了。
编辑完“/etc/syslog”文件之后，还必须运行“killall –HUP syslogd”，这样所做的改变才会生效。这个命令发送“HUP”信号给syslog守护进程，通知守护进程重新读取配置文件。
Syslogd
允许把消息发送给syslogd的程序不仅限于系统程序（例如，守护进程）和内核，任何程序只要使用syslog()的C语言函数就能把消息发送给syslogd。这篇文章不是介绍syslog函数的，如果需要得到这函数的信息可以用“man 3 syslog”命令查看，但是如果你只是想试着发一些消息给syslogd可以用logger命令。如果你在一个终端窗口中正在运行“tail –f /var/log/debug”命令，可以试着在另一个终端窗口运行“logger –p user.debug “Hello, world!””。这个消息很快就会在第一个终端窗口中显示出来。请注意用“-p”参数设置消息的“设备”和“优先级”。RedHat的用户必须用“tail –f /var/log/messages”和“logger –p user.info “Hello, world!””命令。
总结
在看完这篇简单的介绍系统日志的文章之后，你可能还想得到更进一步的信息，那么最好的方法就是查看man帮助。用“man 8 sysklogd”查看syslogd守护进程的信息；用“man 5 syslog.conf”查看配置文件的格式；如果你很想知道内核是怎么处理消息的，可以用“man 8 klogd”；用“man 3 syslog”查看有关系统日志的C语言函数；最后，还可以用“man 1 logger”查看这个命令的用法。
发布人:netbull 来自:LinuxAid