【Kevin小案例】Inode造成的生产库停止服务

显示全部楼层 · 2011-8-31 15:27:58

一个三节点Rac，第三个节点，用户连接时，报告：
ORA-02002: error while writing to audit trail
ORA-09925: Unable to create audit trail file
Linux-x86_64 Error: 28: No space left on device
这个错误一看，太明显不过了，audit空间满了。生产库发生这么严重的问题，心立刻纠了起来。
因为所有的服务器都有Grid Control监控，如果mount point容量超过阀值的话，会触发警报邮件，我们收到邮件后，要第一时间清理。
难道我们从上万封邮件中miss了这封邮件？
第一时间登录上去检查，这个库audit的路径是：
/prod/product/corp_bac1/audit/trail
查看了下这个mount point：
node3[oracle]_corp_bac3> df -h|grep /prod/product

34G 27G5.1G84% /prod/product
奇怪，挂载点并没满
node3[oracle]_corp_bac3> df -h|grep /prod/product

34G 27G5.1G84% /prod/product
难怪Grid Control没有触发警报。

那为什么会报Linux-x86_64 Error: 28: No space left on device”？很典型的数据库的错误，用户不会无中生有。
进入audit目录ls -ltr看一下，整个屏幕立刻开始刷：
06:54 corp_bac3_ora_20624_2e.aud
06:54 corp_bac3_ora_20621_38.aud
06:54 corp_bac3_ora_20618_32.aud
06:54 corp_bac3_ora_20615_38.aud
06:54 corp_bac3_ora_20612_33.aud
06:54 corp_bac3_ora_20688_3c.aud
06:54 corp_bac3_ora_20685_34.aud
06:54 corp_bac3_ora_20682_3e.aud
06:54 corp_bac3_ora_20679_3e.aud
06:54 corp_bac3_ora_20676_3e.aud
06:54 corp_bac3_ora_20673_34.aud
06:54 corp_bac3_ora_20669_37.aud
06:54 corp_bac3_ora_20666_33.aud
06:54 corp_bac3_ora_20663_3c.aud
06:54 corp_bac3_ora_20660_32.aud
.........
.........
整个屏幕刷了几页还只是一分钟内产生的aud文件。
赶紧cancel掉，想统计一下目录下audit文件数量：
[oracle@node3 trail]$ ls -F |grep /|wc
运行了10分钟还没结果，只能cancel掉。
到了这一步已经有了猜测，看来是由于太过大量的audit文件造成了Inode消耗殆尽。
$ df -h -i
Filesystem
Inodes IUsed IFree IUse% Mounted on
/dev/mapper/rootvg-rootvol

15M134K 15M1% /
/dev/cciss/c0d0p165K46 65K1% /boot
tmpfs
16M74 16M1% /dev/shm
/dev/mapper/rootvg-lv_data

5.6M4.4K5.6M1% /data
/dev/mapper/cihcispdb716_grid_vg-gridvol

2.2M473K1.7M 22% /prod/grid
/dev/mapper/cihcispdb716_product_vg-productvol

4.3M4.3M0K100% /prod/product
3.24.148.15:/vol/database_backup

31M 37K 31M1% /prod/backup
3.24.148.13:/vol/cis_orasoft

31M5.5M 25M 19% /cis_orasoft
果然如此。确定了问题，解决起来就简单了，清理audit文件。
每个服务器上都有purge的脚本，定时清理7天或3天前的日志文件，怎奈这个audit文件夹有点变态，每分钟都生成几百个audit file，purge脚本还没来得及清理，就产生了太多的细碎文件。
重新设置purge脚本清理包括当天产生的audit文件，运行了一会后再看：
[oracle@node3 11.2.0]$ df -h -i /prod/product
Filesystem
Inodes IUsed IFree IUse% Mounted on
/dev/mapper/cihcispdb716_product_vg-productvol

4.3M3.8M444K 90% /prod/product
已经释放了一部分Inode，尝试连接第三个节点OK，用户那也反映恢复正常。初步解决。
下面就是分析为什么会产生这么多audit file了。这个数据库已经运行了一年，所以这个问题肯定是这2天新产生的，而另外2个节点都很正常。所以问题肯定是出在这个节点上。到底是什么破程序反复登录造成了这个结果？
查看audit文件中的信息：
[oracle@node3 trail]$ cat corp_bac3_ora_10000_60.aud
Audit file /prod/product/corp_bac1/audit/trail/corp_bac3_ora_10000_60.aud
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
ORACLE_HOME = /prod/product/11.2.0/db
System name:Linux
Node name:node3
Release:2.6.18-164.el5
Version:#1 SMP Thu Sep 3 04:15:13 EDT 2009
Machine:x86_64
Instance name: corp_bac3
Redo thread mounted by this instance: 3
Oracle process number: 71
Unix process pid: 10000, image: [url=mailto

racle@cihcispdb716]oracle@cihcispdb716[/url] (TNS V1-V3)

Mon Mar5 03:47:01 2012 -05:00
LENGTH : '155'
ACTION :[7] 'CONNECT'
DATABASE USER:[1] '/'
PRIVILEGE :[6] 'SYSDBA'
CLIENT USER:[6] 'oracle'
CLIENT TERMINAL:[0] ''
STATUS:[1] '0'
DBID:[10] '2086602188'
通过提供的process pid: 10000去找，这个PID不存在：
[oracle@node3 11.2.0]$ ps -ef|grep 10000
oracle429360510 20:35 pts/17 00:00:00 grep 10000
不过也不算一无所获，起码可以通过SYSDBA确定是本地连接的了。
应该是本地的一些脚本和监视工具造成的。
剩下的检查过程就不写了，最后发现是一个收集统计信息的脚本造成的：
/data/oracle/admin/gather_part_stat.sh corp_bac3 AAPROFILE SM_RAWDATA_MEAS_30000
这个脚本入参分别是用户名和表名。而这个表最近删除掉了，结果脚本中的某一处取值得到了空值，从而造成了无线循环。
注释掉脚本。
解决。

千问 · 2011-8-31 15:27:58

遇到过类似情况，单个文件夹下如果文件数过多，确实会引起极大的性能问题，就是ls都要很长时间。好像每种os都还有类似情况。

千问 · 2011-8-31 15:27:58

ysping 发表于 2012-3-8 10:00
遇到过类似情况，单个文件夹下如果文件数过多，确实会引起极大的性能问题，就是ls都要很长时间。好像每种os ...
恩，这里更严重些，INODE消耗殆尽导致虽然还有很大空余容量，但是已经无法新建文件了，所以造成了停止服务。每种OS每种filesystem应该都有最大文件数的限制。

千问 · 2011-8-31 15:27:58

幸好你产生的文件的句柄已经释放了，不然处理起来更加麻烦点

千问 · 2011-8-31 15:27:58

xifenfei 发表于 2012-3-8 10:08
幸好你产生的文件的句柄已经释放了，不然处理起来更加麻烦点
audit文件的话文件句柄不释放那就是Oracle的bug了,这么多文件, 如果不释放, 不用等这个INODE出现问题,也早就到达:
oracle soft nfile
oracle hard nfile
的限制了. 然后就是其它的问题.更严重

千问 · 2011-8-31 15:27:58

千问 · 2011-8-31 15:27:58

up
得出的感触是，bug无处不在。就是这么一个简单的收集统计信息的小脚本，都能出这么严重的bug。

千问 · 2011-8-31 15:27:58

本帖最后由 jieyancai 于 2012-3-8 16:08 编辑
solaris环境下遇到过inode耗尽，明明空间还有几十G，呵呵
原因是备份了太多地图小图片。
df -F ufs -oi

千问 · 2011-8-31 15:27:58

这些都是OS的基本知识吧

千问 · 2011-8-31 15:27:58

维护中什么问题都有