懒得整理了,直接把故障分析报告黏贴上来了。
【故障基本信息描述】
故障基本信息 |
2012年8月07日上午08:15左右,系统管理员接到后置应用人员反映批处理出现了异常,经检查发现是数据库服务器的根目录/和oracle软件安装目录/u01都满了,临时删除一些日志后后置批处理继续。影响时间:2012-08-07.04:00 – 2012-08-07.08:30,共计3小时30分。 |
故障处理过程 |
2012年8月07日 【约08:15】后置应用人员通知系统管理员,批处理出现了异常,要求协助处理。 【约08:25】经排查发现是由于数据库服务器1的根目录/和oracle软件安装目录/u01都写满了所致。 【约08:30】临时删除掉一些日志后批处理继续进行。 【约09:30】经过统计发现根目录/的实际使用空间仅为10G,而系统上显示的却是已使用了39G,怀疑是根目录上的文件被删除后空间没有被释放。 【约11:00】经过排查发现的确是oracle用户的sendmail进程占据了约20G的临时文件没有被释放,把oracle用户的sendmail进程kill掉后空间释放。 【约13:10】经排查发现oracle软件安装目录/u01满了是由于当前数据库节点在system级别设置了10046 event所致。 【约13:20】把system级别的10046 event关闭就不会再记录那么多trace日志。
|
系统分析 |
2012年08月07日早上04:00至2012年08月07日上午8:30,后置批处理出现了异常,原因是由于数据库服务器1的根目录/和oracle软件安装目录/u01都被写满所致,问题分析过程如下: 问题1,oracle软件安装目录/u01被写满: /u01目录被写满是由于记录了过多的trace日志所致,这些日志中最大的可达20G,而/u01目录的大小只有100G: [root@dm01db01 trace]# du -sm *|awk '{if ($1 > 256){print $1" "$2}}' 1143 SRCBFIN1_j001_77325.trc 2588 SRCBFIN1_lck0_12400.trc 2753 SRCBFIN1_lms0_12338.trc 2726 SRCBFIN1_lms1_12343.trc 1053 SRCBFIN1_ora_71039.trc 20713 SRCBFIN1_ora_71049.trc 1326 SRCBFIN1_ora_71051.trc 1048 SRCBFIN1_ora_71055.trc 截取部分trace日志内容如下:
通过日志的内容怀疑是数据库在system级别启用了10046 event trace,通过alter日志发现的确是在8月3日启用system级别的10046 event trace: Fri Aug 03 18:16:48 2012 OS Pid: 95899 executed alter system set events '10046 trace name context forever,level 12' 使用以下命令检查当前的event 级别: SRCBFIN1@SYS> oradebug setmypid SRCBFIN1@SYS> oradebug eventdump system sql_trace level=12 原来数据库管理员最近在协助oracle工程师分析后置Exadata上使用insert /*+ append */效率低的问题,需要进程抓取一些10046 event trace,本来是要设置成session级别的但是错误的写成了system级别,然后没有及时关闭,才导致了后续新建立的连接都会以及其详细的日志进行记录,最终导致了/u01目录由于没有及时清理而被写满,从而造成了8月7日后置批处理异常。 使用如下命令关闭10046 event trace: alter system set events '10046 trace name context off'; 同时oracle工程师建议把trace日志大小进行限制,即建议修改系统参数max_dump_file_size值大小为1G(=2097152个文件系统块大小(512字节,select max(lebsz) os_block_size from x$kccle;)),这些参数都是即时生效。 alter system set max_dump_file_size=2097152 scope=both sid='*';
问题2,根目录/被写满: 对根目录/进行du统计发现/var/目录空间使用率最大,经过逐层过滤后发现是/var/spool/clientmqueue目录里面的一个临时文件比较大,达到20G: [root@dm01db01 clientmqueue]# ls -l dfq76AUB4H003918 -rw-rw---- 1 oracle smmsp 20224466944 Aug 5 13:30 dfq755U1Tg026331 于是把这个文件删除,但是还是发现根目录的空间并没有被释放: [root@dm01db01 /]# df Filesystem Size Used Avail Use% Mounted on /dev/mapper/VGExaDb-LVDbSys1 30G 27G 1.3G 96% / /dev/sda1 502M 30M 447M 7% /boot /dev/mapper/VGExaDb-LVDbOra1 99G 63G 31G 68% /u01 tmpfs 81G 48G 33G 60% /dev/shm /dev/mapper/VGExaDb-LVDbBak1 30G 315M 28G 2% /backup hzhisdb:/hisbackup 5.0T 4.7T 389G 93% /hisbackup hzhisdb:/exbak 4.9T 3.2T 1.8T 64% /exbak 经过排查发现这个文件仍然被oracle的sendmail进程所占用: [root@dm01db01 /]# lsof | grep deleted oracle 463 oracle 14w REG 253,3 3924 9373151 /u01/app/oracle/diag/rdbms/srcbfin/SRCBFIN1/trace/SRCBFIN1_ora_463.trc (deleted) oracle 463 oracle 15w REG 253,3 618 9373152 /u01/app/oracle/diag/rdbms/srcbfin/SRCBFIN1/trace/SRCBFIN1_ora_463.trm (deleted) sendmail 3918 oracle 3uW REG 253,0 20224466944 3867381 /var/spool/clientmqueue/dfq76AUB4H003918 (deleted) 杀掉改进程后空间被释放: [root@dm01db01 /]# kill -9 3918 [root@dm01db01 /]# df Filesystem Size Used Avail Use% Mounted on /dev/mapper/VGExaDb-LVDbSys1 30G 8G 21.3G 31% / /dev/sda1 502M 30M 447M 7% /boot /dev/mapper/VGExaDb-LVDbOra1 99G 63G 31G 68% /u01 tmpfs 81G 48G 33G 60% /dev/shm /dev/mapper/VGExaDb-LVDbBak1 30G 315M 28G 2% /backup hzhisdb:/hisbackup 5.0T 4.7T 389G 93% /hisbackup hzhisdb:/exbak 4.9T 3.2T 1.8T 64% /exbak
|