作者简介
石云华，Exadata中国用户组联合创始人，ORACLE ACE。毕业后一直从事Oracle数据库第三方运维服务工作，拥有十余年电信运营商、保险、税务、电力行业核心系统数据库运维经验。现就职于北京海天起点技术服务股份有限公司，oracle数据库专家组成员，Exadata部门负责人。个人著作有《Exadata实施运维指南》，《Oracle Exadata性能优化》
案例概要：
客户反映Exadata的监控工具EM12c中，显示存储节点2状态显示为异常，但可以正常登录该存储节点，并且该存储节点的服务运行正常。
案例分析及处理：
使用oracle操作系统用户，分别在计算节点db01和db02上，执行如下命令来检查存储节点的状态。
ssh -l cellmonitor dm01celadm01 cellcli -xml -e 'list cell attributes msStatus' ssh -l cellmonitor dm01celadm02 cellcli -xml -e 'list cell attributes msStatus' ssh -l cellmonitor dm01celadm03 cellcli -xml -e 'list cell attributes msStatus' |
以上命令在存储节点1和3上运行正常，但存储节点2上运行异常，具体日志如下：
[oracle@dm01dbadm02 ~]$ ssh -l cellmonitor dm01celadm02 cellcli -xml -e 'list cell attributes msStatus' The authenticity of host 'dm01celadm02 (10.20.249.54)' can't be established. RSA key fingerprint is 65:f4:9b:c8:7a:61:52:93:f1:ed:93:12:10:3c:2d:6c. Are you sure you want to continue connecting (yes/no)? yes Warning: Permanently added 'dm01celadm02' (RSA) to the list of known hosts. CELL-01528: Unable to create the log file in directory /opt/oracle/cell/cellsrv/deploy/log. Error: opt/oracle/cell/cellsrv/deploy/log/cellcli.lst.cellmonitor.0.lck: No space left on device. <?xml version="1.0" encoding="utf-8" ?> <cli-output> <cell> <msStatus>running </msStatus> </cell> </cli-output> [oracle@dm01dbadm02 ~]$ |
从存储节点2的命令输出可以看出，在检查存储节点状态时报了CELL-01528错误，提示在/opt/oracle/cell/cellsrv/deploy/log目录下无法创建日志文件，原因是磁盘上没有足够的空间。
检查存储节点的文件系统使用情况，具体命令如下。
[root@dm01celadm02 ~]# df -h Filesystem Size Used Avail Use% Mounted on /dev/md5 9.9G 5.1G 4.4G 54% / tmpfs 63G 4.0K 63G 1% /dev/shm /dev/md7 3.0G 962M 1.9G 34% /opt/oracle /dev/md4 114M 26M 83M 24% /boot /dev/md11 5.0G 1.3G 3.5G 27% /var/log/oracle |
可以看出该主机上的每个文件系统都有大量的剩余空间，但仍然提示没有磁盘空间，这种情况很可能是文件系统上的inode耗尽了。
检查存储节点的inode使用情况，具体命令如下。
[root@dm01celadm02 trace]# df -i Filesystem Inodes IUsed IFree IUse% Mounted on /dev/md5 655360 37489 617871 6% / tmpfs 16463215 2 16463213 1% /dev/shm /dev/md7 196608 7402 189206 4% /opt/oracle /dev/md4 30120 38 30082 1% /boot /dev/md11 327680 327680 0 100% /var/log/oracle |
可以发现，是由于/var/log/oracle文件系统的inode用光了，导致无法创建新文件。而/var/log/oracle文件系统的inode数量为327680，但这些inode已经用光，说明该文件系统中存在大量小文件。
检查存储软件日志目录中文件数量多少，具体命令如下。
$ ls -sort |wc -l 45793 |
可以看出，该目录中生成的trace文件非常多，查看该目录中的内容，基本上全是cellofltrc开头的trace文件，并且这些trace文件的生成时间非常有规律，每个小时的整点准时生成。
检查存储软件日志，内容如下所示。
Tue Mar 06 22:00:00 2018 Time went backwards. Old Time: 03-06-2018 22:00:01.965. New Time: 03-06-2018 22:00:00.480. Time went backwards. Old Time: 03-06-2018 22:00:01.965. New Time: 03-06-2018 22:00:00.781. Cellsrv will have to be restarted, since backward drift in time was more than 300 milliseconds Tue Mar 06 22:00:00 2018 [RS] monitoring process /opt/oracle/cell/cellsrv/bin/cellrsomt (pid: 21446) returned with error: 128 Errors in file /opt/oracle/cell/log/diag/asm/cell/dm01celadm02/trace/svtrc_21448_main.trc (incident=89): ORA-00600: internal error code, arguments: [ossmisc:ossmisc_timer_ticks], [], [], [], [], [], [], [], [], [], [], [] Incident details in: /opt/oracle/cell/log/diag/asm/cell/dm01celadm02/incident/incdir_89/svtrc_21448_main_i89.trc Errors in file /opt/oracle/cell/log/diag/asm/cell/dm01celadm02/trace/svtrc_21448_main.trc (incident=90): ORA-00600: internal error code, arguments: [MutexObject::pthread_rwlock_tryrdlock2], [GenTimeStats HT], [FILE:/ade/aime_oss_341446/oracle/oss//src/server/if/LockedHashTable.h LINE:444], [139814531237632], [139814659644992], [], [], [], [], [], [], [] ORA-00600: internal error code, arguments: [ossmisc:ossmisc_timer_ticks], [], [], [], [], [], [], [], [], [], [], [] Incident details in: /opt/oracle/cell/log/diag/asm/cell/dm01celadm02/incident/incdir_90/svtrc_21448_main_i90.trc |
从存储软件的日志文件中可以看到以上报错日志，同时也是非常有规律，每小时的整点产生，具体报错原因是由于操作系统的时间往后调整，导致存储软件出现故障，这个问题在MOS文档（Bug 24327559和Bug24340998）中都进行了解释，这个ORA-600错误并不是存储软件的BUG，而是由于某种原因（人为地修改系统时间或NTP时钟服务器存在同步问题）导致操作系统时间回退，所以存储软件必须重新启动。
(3)、检查NTP时钟同步服务配置情况，以下是收集的信息内容。
[root@dm01celadm01 ~]# cat /etc/ntp.conf |grep -v ^# |grep -v ^$ driftfile /var/lib/ntp/drift restrict default kod nomodify notrap nopeer noquery restrict -6 default kod nomodify notrap nopeer noquery restrict 127.0.0.1 restrict -6 ::1 includefile /etc/ntp/crypto/pw keys /etc/ntp/keys restrict 10.20.0.0 mask 255.255.0.0 nomodify notrap server 127.127.1.0 fudge 127.127.1.0 stratum 1 [root@dm01celadm01 ~]# [root@dm01celadm01 ~]# ntpq -p ntpq: read: Connection refused [root@dm01celadm01 ~]# [root@dm01celadm01 ~]# ntpstat Unable to talk to NTP daemon. It is running? [root@dm01celadm01 ~]# [root@dm01celadm01 ~]# ps -ef |grep ntp root 29798 28700 0 10:34 pts/0 00:00:00 grep ntp [root@dm01celadm01 ~]# [root@dm01celadm01 ~]# service ntpd status ntp is stopped [root@dm01celadm01 ~]# |
从以上收集的信息可以看出，当前的NTP服务已经关闭。
故障原因及解决方案：
存储节点2的系统时间运行比较快，为了保证整个集群的时间保持一致，于是客户在存储节点2部署了crontab定时任务，每1小时整点让存储节点2与时钟服务器进行ntpdate同步，这一操作导致存储节点的时间往回调整，而存储软件不允许操作系统时间往后调整，否则存储软件会报错并自动重启存储软件，存储软件的重启过程中会产生大量的日志文件，最终这些小日志文件耗光了所有的inode。
临时解决办法：
1、归档及删除日志文件释放inode，同时重启存储节点2，保证一个干净的环境。
2、停止使用ntpdate的方式同步存储节点的时钟。
最终解决办法：
在Exadata环境中配置NTP时钟服务器，让存储节点与NTP时钟服务器进行同步。目前，客户已经在Exadata环境中配置了NTP时钟服务器，存储节点2已经与该NTP时钟服务器进行同步，该故障已经完全解决，存储软件未报任何异常信息。
