crond-sendmail-postdrop导致Linux定期死掉的完整解决过程实录

还是简单才最好

问题描述

一台2004年配置的RedFlag Server 4.1数据库服务器，基本软件是Oracle9i，没有按照X窗口系统。一次发现日志磁盘分区无法写入，问题是sendmail导致大量小的文件，占满了inode编号，从而导致虽然磁盘仍有空间，但是inode用完的局面。由于本系统用途为单一的数据库服务器，所以邮件几乎没什么用途，于是删除了这些小文件，然后chkconfig停止了sendmail服务。于是之后发生了如下的故事...


理论上说，纯命令行的Linux系统相当稳定，可是这台机器最近总是不定期一周左右死掉。症状为：系统无法登陆，以登陆还是重复显示登陆提示符，系统的各项服务如sshd和最基本的数据库服务也不能工作。由于已经无法登入系统，所以排错相当困难。硬重启后系统则正常，只是不久后问题依旧，非常烦人。
排错过程

maillog日志文件占满分区空间

照例查看系统日志，/var/log/message、/var/log/secure、dmesg等，没有发现异常。df -h发现日志所在的文件系统分区使用率100%了，是不是因为这个原因系统死掉呢？如如何根据日志判断呢？（ToDo)。
记得之前有一次因为这个分区占用较大，一气之下把/var/log整个目录都rm -rf了，导致了一些关键的目录和文件被删除，如/var/log/rflogview/以及其下面的文件，这些是系统日志文件，文件不存在了，syslogd也就无法写入（syslogd不会自动创建不存在的日志文件），所以一些关键的系统日志都被丢失了。


du -sh 查看找到了一个巨大的文件/var/log/mailog。head、tail查看内容，发现全是同样的内容行，如下：
May 13 15:29:23 lcha2 postfix/postdrop[1443]: warning: mail_queue_enter: create file maildrop/383480.1443: No such file or directory

May 13 15:29:23 lcha2 postfix/postdrop[1269]: warning: mail_queue_enter: create file maildrop/330426.1269: No such file or directory

May 13 15:29:23 lcha2 postfix/postdrop[1439]: warning: mail_queue_enter: create file maildrop/357169.1439: No such file or directory

May 13 15:29:23 lcha2 postfix/postdrop[1654]: warning: mail_queue_enter: create file maildrop/984222.1654: No such file or directory

使用 tail -f /var/log/maillog，发现每秒都有几乎相同的文本行输出。按照上面的日志内容，判定是postfix这个套件的postdrop程序发出的日志。是谁启动了postdrop呢？
使用pstree，结果如下：


init-+-aacraid
|-atd
|-bdflush
|-crond---125*[crond---sendmail---postdrop]

可见crond守护进程启动了sendmail，进而启动了postdrop。查看crond的配置， crontab -e，都没有发现几秒就启动的程序，所以可能是sendmail自己一旦邮件发送不成功，就持续重新发送而导致持续启动postdrop，而postdrop总是执行失败，导致持续写入日志到日志文件。日志文件增大的速率超过了logrotate的删除频率，所以占据了100%的磁盘空间。


由于sendmail没有退出，导致启动它的crond也不能退出，从而导致多个crond进程并存。


找到了问题，解决起来相对简单。一种方式就是不让postdrop产生的日志写入日志文件，这通过修改/etc/syslog.conf文件达成；第二种方式是增大logrotate的删除频率，这通过修改logrotate的crond像以及/etc/logrotate.conf配置文件达成；第三就是找到postdrop失败的原因，修正使其能够成功进行。最简单的就是第一种了，也能满足目前的需要，所以就采取了第一种方式。


修改syslog.conf使得不记录mail的warning信息，修改前如下：
mail.*                                                        /var/log/maillog

修改后
mail.err  /var/log/maillog
这样就通过提高日志记录的级别来舍弃了mail类的warning级别日志。


service syslog restart重新启动syslogd。然后tail -f /var/log/maillog，在没有上面类似日志的输出了。
文件打开数量达到极限

然而，几天后重新出现死机的现象，不过这次在现场显示器上看到了类似 "cannot open shared object file: Too many open files in system"的信息。在Linux中，“一切都是文件”，程序文件本身、各种库文件、管道、设备、网络连接等等都是文件。上述信息说明，系统打开的文件数量到达了极限，从而导致无法打开新文件，当然也就无法执行程序。通过 sysctl -a 可以看到fs.file-max = 131072，这个数字也不小了。那么是谁打开了这么多的文件呢？通过lsof
查看发现名为sendmail和postdrop的多个进程，每个进程都打开了多个文件。通过 ps -e | grep sendmail | cut -d ' ' -f2 | xargs kill，以及ps -e | grep postdrop| cut -d ' ' -f2 | xargs kill，杀死所有sendmail和postdrop进程后，再lsof发现打开的文件数骤减。


前面已经给出了pstree的结果，发现是cron启动了sendmail，sendmail启动了postdrop。临时写了一个小的测试脚本，来看sendmai的启动频率。


while true
do
date +%H:%M:%S >> 1.txt
ps -e | grep sendmail | wc >>1.txt
sleep 5
done从结果文件1.txt中发现每10分钟，就会启动一个sendmail进程。crontab里有个没有这个频率的启动项，但有一个每5分钟自动网络校时的启动项。把这个项注视掉，重新启动crond，发现仍然有sendmail的启动，从而排除了这个原因。难道是crond本身每10分钟就自动发送邮件吗？按照man 5 crontab的解释，把/etc/crontab的MAILTO设为""，这样crond就不会发送邮件了。重新启动crond服务，发现crond仍然10分钟启动一次sendmail，太奇怪了！干脆直接关闭crond服务，然后再也没有新的sendmail进程产生。难道是crontab被黑了？为什么MAILTO=""了，还会调用sendmail呢？把所有的sendmail进程都kill掉，然后启动crond，
仍然会生产sendmail，看来crond和sendmail的关系绝非一般。


被忽略的/etc/cron.d

弄了半天，发现了/etc/cron.d目录下存在一个文件，而crond会自动读取其中的配置信息，正好这个文件里有一个项就是每10分钟执行一次systat软件包的命令，测试表明这个命令由于所写日志文件不存在而导致报错，一旦报错，crond就会sendemail（不管MAILTO的值如何？）。在这条命令后面加上 &>/dev/null后，发现crond不再启动sendmail进程。


原来内容：
# run system activity accounting tool every 10 minutes

*/10 * * * * root /usr/lib/sa/sa1 1 1

# generate a daily summary of process accounting at 23:53

53 23 * * * root /usr/lib/sa/sa2 -A



其中的命令会报错：
[iyunv@lcha2 root]# /usr/lib/sa/sa1 1 1

Cannot open /var/log/sa/sa20: No such file or directory



修改后：
# run system activity accounting tool every 10 minutes

*/10 * * * * root /usr/lib/sa/sa1 1 1 &>/dev/null

# generate a daily summary of process accounting at 23:53

53 23 * * * root /usr/lib/sa/sa2 -A &>/dev/null



全过程总结



心得体会

• 日志文件是系统分析的关键，要确保所有日志文件目录可用，如果不可用，syslogd不会自动创建它们，也就失去了记录日志的机会！
  
• crond，logrotate，syslogd相互配合
  
• crond和sendmail的关系绝非一般，crontab中MAILTO设置了空，crond仍然会调用sendmail发送邮件，解决方式是把crond执行的命令最后加上 &> /dev/null。
  
• 要全面了解一个软件包，比如cron.d是crond的一部分，作者就就吃亏在这个上面
  
• 多动手测试，熟练使用bash命令