crontab导致CPU异常的问题分析及处理

今天查看数据库负载没有发现问题，但是当我使用top命令的时候，发现有一个进程占用了大量的cpu资源而且已经执行很长时间了。这一下子引起了我的注意。PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND25807 oraccbs1 25 0 8728 732 564 R 100.0 0.0 2021:19 /bin/sh -c /opt/app/Oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.log13578 oraccbs1 18 0 40.2g 49m 29m D 61.0 0.0 6:40.18 oraclePRODB (LOCAL=NO)17085 oraccbs1 18 0 40.2g 48m 24m R 40.6 0.0 36:44.43 oraclePRODB (LOCAL=NO)30894 oraccbs1 18 0 40.3g 56m 27m D 38.1 0.0 54:40.46 oraclePRODB (LOCAL=NO)10616 oraccbs1 18 0 40.3g 54m 24m R 36.8 0.0 28:15.49 oraclePRODB (LOCAL=NO)17089 oraccbs1 18 0 40.2g 49m 25m R 36.8 0.0 60:11.90 oraclePRODB (LOCAL=NO)12103 oraccbs1 18 0 40.2g 31m 22m R 35.6 0.0 149:38.06 oraclePRODB (LOCAL=NO)30898 oraccbs1 18 0 40.2g 50m 32m D 35.6 0.0 56:03.90 oraclePRODB (LOCAL=NO)对于这个脚本我比较陌生，一般这些维护性的工作主要都是客户来做的。尝试查看了下这个脚本的内容，发现是一个检测脚本，脚本的内容很清晰,是来监控归档目录和home目录的空间使用情况，当超过阀值的时候，就发送短信给响应的人来处理。内容大体如下：#Send Short Message if %used greater than 80% : ARCHIVEPERC_ARCH_USED=`df -P ${ARCH_PATH}|awk '{ print $5 }'|grep "%"|tr -d "%"`export casename=`uname -n`_${database}_Percent_Archive_Used_IS_${PERC_ARCH_USED}if [[ $PERC_ARCH_USED -gt 80 ]]; thensqlplus -s xxxxx @$myDir/Sql/sendsms.sql $casenamefi#Send Short Message if %used greater than 80% : $ORACLE_HOMEPERC_HOME_USED=`df -P ${HOME_PATH}|awk '{ print $5 }'|grep "%"|tr -d "%"`export casename=`uname -n`_${database}_Percent_HOME_Used_IS_${PERC_HOME_USED}if [[ $PERC_HOME_USED -gt 80 ]]; thensqlplus -s xxxxxx @$myDir/Sql/sendsms.sql $casenamefi这样一个脚本的执行肯定执行一次就完了。它是从哪里执行的呢，首先想到的就是crontab。crontab是在系统级作为作业自动执行的利器，可以进行各种细粒度的配置，使用也很方面。先来查看一下crontab的情况，结果在crontab的最后发现一个配置就是正在执行的job.>crontab -l#------------------------------------------------# Test Log DB for house keeping .....#------------------------------------------------#0,30 * * * * /opt/app/oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.log这样来看似乎问题找到了原因，但是奇怪的是根据crontab里面的设置，这个job已经被禁用了,怎么还在运行?毕竟这个问题还不能完全肯定是操作问题还是其他的原因导致的，就先不轻率的决定，把问题分给客户，从我的角度来说，怎么才能得到一些信息来说明这个问题才是关键。首先是crontab的执行频率问题。如果没有接触过crontab可能会有些陌生。crontab命令包含6个参数，命令的一些基本说明如下：* * * * * command分 时 日 月 周 命令第1列表示分钟1～59 每分钟用*或者 */1表示第2列表示小时1～23（0表示0点）第3列表示日期1～31第4列表示月份1～12第5列标识号星期0～6（0表示星期天）第6列要运行的命令在这个例子中。0,30是第一个参数，就代表每个小时的0分，30分执行一次下面的脚本。0,30 * * * * /opt/app/oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.log如果要求脚本在指定的时间段，比如只在5分，20分，30分的时候执行，5,20,30 * * * * /opt/app/oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.log 如果要求脚本在指定的时间段，比如只在每天晚上的11:30执行，就可以写成下面的形式。30 23 * * * /opt/app/oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.log从配置来看，job是每隔半个小时执行一次，而且所做的检查工作也不复杂，执行时间应该会很短。配置中这个job已经被禁用，如果我们能够证明这个job是通过crontab执行的就能够说明是操作问题。因为crontab里面已经禁用，但是实际上job还在运行。通过进程的信息，我们知道这个进程已经执行了近2021分钟，我们来推算一下执行的时间。2021/60=33个小时，从下午3点往前推33个小时，就是在29号早晨的7点左右开始执行的。PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 25807 oraccbs1 25 0 8728 732 564 R 100.0 0.0 2021:19 /bin/sh -c /opt/app/oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.log这个时候日志就是最好的证明工具，可以在/var/spool/mail/oraccbs1下面找到相应的日志。日志中最近的一次执行时间是在昨天的早晨7:30,之后就没有任何相关的日志了。Mon Dec 29 07:30:01 2014Return-Path: <oraccbs1@localhost.localdomain>Received: from localhost.localdomain (xxxxx[127.0.0.1])by localhost.localdomain (8.13.8/8.13.8) with ESMTP id sBT0U1mr013412for <oraccbs1@localhost.localdomain>; Mon, 29 Dec 2014 07:30:01 +0700Received: (from oraccbs1@localhost)by localhost.localdomain (8.13.8/8.13.8/Submit) id sBT0U1Jh013347;Mon, 29 Dec 2014 07:30:01 +0700Date: Mon, 29 Dec 2014 07:30:01 +0700Message-Id: <201412290030.sBT0U1Jh013347@localhost.localdomain>From: root@localhost.localdomain (Cron Daemon)To: oraccbs1@localhost.localdomainSubject: Cron <oraccbs1@xxxxxx> /opt/app/oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.logContent-Type: text/plain; charset=UTF-8Auto-Submitted: auto-generated/bin/sh: fork: Resource temporarily unavailableFrom oraccbs1@localhost.localdomain Mon Dec 29 07:30:05 2014。。。。得到了这些基本信息，就能够基本确定问题了。至于crontab的修改，可以使用crontab -e来完成。感觉就跟vi操作一样。客户做了确认之后，手工kill掉了那个job,那个问题就解决了。有很多朋友反馈说为什么会导致CPU异常，因为问题已经修复了，我就从支离破碎的日志中做了简单的分析。可以通过上面的日志看到fork: Resource temporarily unavailable这个问题，说明在执行crontab job的时候发生了问题，这个问题可能是数据库中其它的资源消耗导致的，也可能是发送消息的环节导致的，因为发送消息的细节是客户来维护，他们不愿意透露 更多的细节，我们只能做主观上的猜测了。不过通过下面的日志能够得到一些信息。就是crontab的job很可能是个僵尸进程。存在两个相同的进程。>ps -ef|grep DailyChkoraccbs1 14187 7786 0 14:59 pts/10 00:00:00 grep DailyChkoraccbs1 25793 1 0 Dec29 ? 00:00:00 /bin/sh -c /opt/app/oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.logoraccbs1 25807 25793 99 Dec29 ? 1-09:58:51 /bin/sh -c /opt/app/oracle/xxxxxx/Script/DailyChk/chk_path_full.ksh PRODB 2>&1 >/opt/app/oracle/Script/DailyLog/chk_path_full.log最后从昨天的top截图中发现了如下的内容，可以基本断定问题是crontab 的那个job成为了僵尸进程导致的。Tasks: 7196 total, 26 running, 7165 sleeping, 0 stopped, 5 zombieCpu(s): 7.8%us, 1.5%sy, 0.0%ni, 90.1%id, 0.1%wa, 0.1%hi, 0.4%si, 0.0%stMem: 363033360k total, 116349772k used, 246683588k free, 2176616k buffers本文来自：Linux学习网