服务器进程异常的原因分析(r6笔记第74天)

现在系统监控的工作处于过渡期，即对于Oracle的还是保留了gridcontrol的监控和报警，同时也保留了zabbix的报警，在发生问题的时候想看看哪个能监控的更到位一些，是否稳定等等，其实这个还真不好说，监控的好与不好都在于使用的情况，标准也不一样，不过从今天这个案例来看，系统级的监控还是zabbix要灵活一些。 今天收到的报警邮件如下： ZABBIX-监控系统: ------------------------------------ 报警内容: Too many OS processes on xxxx_p@10.127.xxxx ------------------------------------ 报警级别: PROBLEM ------------------------------------ 监控项目: Number of processes：2009 ------------------------------------ 报警时间:2015.09.30-05:15:00

首先说明一下情况，一般的系统session数都在1000左右，在定义zabbix监控项的时候还是认为能够限定一下系统级的进程数，所以就给了一个较大的阀值2000,认为还是做一个系统级的监控为好。所以系统在早晨业务低峰期出现这种问题，还是有些奇怪的。 首先联想到的就是可能数据库中存在着大量的sql语句，但是连接没有合理释放。但是我猜中了开始，没有猜中结局。 首先查看数据库的DB time,没有发现暴涨。 BEGIN_SNAP END_SNAP SNAPDATE LVL DURATION_MINS DBTIME ---------- ---------- ---------------------- --------- ---------- 23356 23357 30 Sep 2015 00:00 1 60 14 23357 23358 30 Sep 2015 01:00 1 60 10 23358 23359 30 Sep 2015 02:00 1 60 4 23359 23360 30 Sep 2015 03:00 1 60 4 23360 23361 30 Sep 2015 04:00 1 60 5 23361 23362 30 Sep 2015 05:00 1 60 21

查看session使用情况。

STATUS CNT ------------- ---------- ACTIVE 35 INACTIVE 643 ---------- sum 678

目前数据库使用的session数大于在700左右，这和报警中的2000多相差甚远。 查看系统io和CPU使用情况也没有发现异常。 Time %iowait %idle 04:50:01 AM 0.02 99.50 05:00:01 AM 0.02 99.36 05:10:01 AM 0.02 99.28 05:20:01 AM 0.03 98.36 05:30:01 AM 0.02 99.02 05:40:01 AM 0.02 99.02 05:50:01 AM 0.02 99.13 06:00:01 AM 0.46 97.33 06:10:01 AM 0.06 98.63 06:20:01 AM 0.02 99.05 06:30:01 AM 0.03 98.63 Average: 0.03 99.24

这个时候有些怀疑是否被报警误导了，但是zabbix好的一点就是可以灵活的定制图形。

可以看到在凌晨开始进程数据开始逐渐增长，到早晨5点多刚好超过了阀值，而且还在不断增长。 我查看问题的时间段在早晨7点多，正好就是进程数暴涨的时间段，根据我得到的session情况，发现session数还是比较稳定，保持在700左右。

所以既然数据层面发现不了问题，那么只能想到就是系统级了。 但是系统级怎么查看呢，似乎还是有些费力。 # ps -ef|wc -l 2545

通过这个发现确实进程数不少，简单看了下进程的情况，发现进程主要都集中在下面三个部分。 root 45465 5415 0 04:13 ? 00:00:00 CROND oracle 45483 45465 0 04:13 ? 00:00:00 /usr/sbin/sendmail -FCronDaemon -i -odi -oem -oi -t -f root oracle 45489 45483 0 04:13 ? 00:00:00 /usr/sbin/postdrop -r

# ps -ef|grep sendmail |wc -l 461

# ps -ef|grep postdrop |wc -l 460

# ps -ef|grep CROND|wc -l 460

等过了会，没有做任何操作，屏幕里就开始输出资源紧张了，看来问题还是有些严重了。 bash: fork: retry: Resource temporarily unavailable bash: fork: retry: Resource temporarily unavailable bash: fork: retry: Resource temporarily unavailable 简单明确了问题，发现是这三个进程占用了大量的进程资源，为了先修复问题，实用下面的脚本kill掉sendmail的进程。 # ps -ef|grep sendmail| awk '{print "kill -9 "$2}' 清理之后马上就恢复了正常。 $ ps -ef|wc -l 1173 这个时候开始逐步分析排查，查看了crontab里面也没有发现频繁的crontab任务。 查看系统日志发现了这么一段内容 /var/log/maillog Sep 30 09:28:51 xxxx postfix/postdrop[42358]: warning: mail_queue_enter: create file maildrop/236034.42358: No space left on device Sep 30 09:28:51 xxxx postfix/postdrop[39782]: warning: mail_queue_enter: create file maildrop/236872.39782: No space left on device Sep 30 09:28:51 xxxx postfix/postdrop[40086]: warning: mail_queue_enter: create file maildrop/237156.40086: No space left on device 但是查看文件系统情况没有问题，空间还是很充足的。 # df -h Filesystem Size Used Avail Use% Mounted on /dev/sda7 6.0G 949M 4.7G 17% / tmpfs 16G 0 16G 0% /dev/shm /dev/sda1 124M 53M 65M 45% /boot /dev/sda2 6.0G 1.6G 4.1G 29% /usr /dev/sda3 4.0G 1.5G 2.3G 40% /var 那么空间充足，为什么还有问题，其实使用df -i 就能看出端倪。 # df -i Filesystem Inodes IUsed IFree IUse% Mounted on /dev/sda7 393216 17569 375647 5% / tmpfs 4103447 1 4103446 1% /dev/shm /dev/sda1 32768 45 32723 1% /boot /dev/sda2 393216 77762 315454 20% /usr /dev/sda3 262144 262144 0 100% /var /dev/sda8 71000064 299827 70700237 1% /U01 df 查看的i选项就是inode的信息，这个命令选项的含义如下： -i, --inodes List inode usage information instead of block usage. An inode (short for index node) contains information about a file such as its owner, permissions, timestamps, and location on the disk. 其实文件本身不大，但是数量巨大，就会有这种问题。可以看到这个目录下有25万个这样的细小文件。 maildrop]# du -sh . 1023M . maildrop]# ll |wc -l 259903 因为这个进程下的文件都是比较早的，所以可以先删除一部分旧文件。 -rwxr--r-- 1 oracle postdrop 471 Mar 20 2015 4B2722D -rwxr--r-- 1 oracle postdrop 471 Mar 20 2015 5C1A038 -rwxr--r-- 1 oracle postdrop 471 Mar 20 2015 6EE0539 -rwxr--r-- 1 oracle postdrop 471 Mar 20 2015 81A5169 -rwxr--r-- 1 oracle postdrop 471 Mar 20 2015 9203979 -rwxr--r-- 1 oracle postdrop 471 Mar 20 2015 A5D4393 -rwxr--r-- 1 oracle postdrop 471 Mar 20 2015 B7B90A0 -rwxr--r-- 1 oracle postdrop 471 Mar 20 2015 CA347A4 当前用户的资源情况如下： $ ulimit -a core file size (blocks, -c) 0 data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 256313 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 65536 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 2047 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited 所以最后使用下面的脚本开始清理这些碎片文件，先腾出来一部分空间来。 find . -mtime +60|xargs ls -lrt|head -100|awk '{print "rm -f " $9}' > ~/clean.sh 清理了部分文件之后，警告信息变成了下面这种。 Sep 30 10:42:01 xxxx postfix/sendmail[15445]: warning: the Postfix sendmail command has set-uid root file permissions Sep 30 10:42:01 xxxx postfix/sendmail[15445]: warning: or the command is run from a set-uid root process Sep 30 10:42:01 xxxx postfix/sendmail[15445]: warning: the Postfix sendmail command must be installed without set-uid root file permissions Sep 30 10:42:16 xxxx postfix/postdrop[15451]: warning: unable to look up public/pickup: No such file or directory 这个部分对自己来说就是新手了，也不敢妄自乱试验，咨询了下linux高手，他们发现sendmail有问题，不知道是最开始初始化的时候没有装好还是其它原因，建议还是重新安装。 然后又开始着实配置各种yum环境，费了一番功夫。 # yum reinstall sendmail 当然安装的时候需要有系统用户smmsp和用户组smmsp,最后重新安装后日志里面就恢复了正常， 这个问题的原因我觉得是一个遗留问题，安装阶段就有点小问题，但是没有引起重视，结果随着时间的推移，慢慢积累成了大问题。 所以通过这个例子可以看到对于inode的监控也是需要的，同时监控异常的进程情况也会提前发现不少问题。