20080708-13故障原因分析.doc

2008年7月8日-13日系统出现故障报告致信息公司： 20080708日发现ARIMS用户不能登陆以及ORACLE数据库报错，经查实和故障修复，现系统已恢复正常。事故原因及修复过程报告如下：一、2008年7月8日故障过程描述： 于2008-07-08日上午9：30接到机场系统室故障电话，称部分新建ARIMS用户不能登录，已用ARIMS客户能正常使用，应用服务器双机监控程序报数据库服务器出现故障现象。我公司接电话后，相关技术人员马上远程进行登录，检查系统配置，发现故障如上所述。因此马上采取应急方案，进行故障解决。经过远程联接，发现后台数据库ARIMS小机出现系统死锁状态，而且远程不能登录系统，因此在远程采取相应解决方案无效后，马上坐车前往机场进行解决，于13：00到达机场现场，进行故障解决。故障现象分析： 到达现场后，发现ARIMS1小机不能远程telnet，但是IP地址可以PING通。从HMC控制台观察，ARIMS1都是处于运行状态中，没有硬件上的报警。排除ARIMS1硬件问题，是软件应用问题。经过进一步检查，发现从HMC控制台不能通过终端登录系统，故障现象与telnet状态一样，长时间的等待，也没有任何报错提示。观察ARIMS应用终端客户，发现一部分原来长期建立联接的用户一直都在线，都能正常工作，而新建的联接不能建立，不能打开ARIMS客户端。说明系统还是处于运行状态，应用还在运行，只是不能新增任务，从而肯定是此主机应用存在问题，而此主机主要应用为ORACLE数据库，ARISM后台数据库应用。因此从ORACLE数据库进行分析，发现不能通过SQL进行联接，因此可以肯定是ORACLE应用出现问题，导致系统出现死锁。在这种情况下，根据小机维护手册，启动应急方案，对ARIMS1进行重启，把ORACLE应用切换至ARIMS2上，恢复ARIMS应用。经过45秒的切换时间，观察ARIMS应用服务器与客户端，发现都能正常工作。 争对ARIMS1故障进一步分析，ARIMS1重启后，进行系统观察系统日志与机器状态，发现系统报文件目录太小，应用出现故障。下图为系统日志输出。# errptIDENTIFIER TIMESTAMP T C RESOURCE_NAME DESCRIPTIONF89FB899 0708150008 P O dumpcheck The copy directory is too small.173C787F 0708124808 I S topsvcs Possible malfunction on local adapterF89FB899 0707150008 P O dumpcheck The copy directory is too small.F89FB899 0706150008 P O dumpcheck The copy directory is too small.F89FB899 0705150008 P O dumpcheck The copy directory is too small.F89FB899 0704150008 P O dumpcheck The copy directory is too small.BFE4C025 0704010008 P H sysplanar0 UNDETERMINED ERRORB9735AF4 0703234508 P H dac1 SUBSYSTEM COMPONENT FAILUREBFE4C025 0703233308 P H sysplanar0 UNDETERMINED ERRORF89FB899 0703150008 P O dumpcheck The copy directory is too small.BFE4C025 0703001808 P H sysplanar0 UNDETERMINED ERRORB9735AF4 0703001708 P H dac1 SUBSYSTEM COMPONENT FAILUREF89FB899 0702150008 P O dumpcheck The copy directory is too small.F89FB899 0701150008 P O dumpcheck The copy directory is too small.F89FB899 0630150008 P O dumpcheck The copy directory is too small.F89FB899 0629150008 P O dumpcheck The copy directory is too small.F89FB899 0628150008 P O dumpcheck The copy directory is too small.F89FB899 0627150008 P O dumpcheck The copy directory is too small.F89FB899 0626150008 P O dumpcheck The copy directory is too small.F89FB899 0625150008 P O dumpcheck The copy directory is too small.F89FB899 0624150008 P O dumpcheck The copy directory is too small.F89FB899 0623150008 P O dumpcheck The copy directory is too small.F89FB899 0622150008 P O dumpcheck The copy directory is too small.F89FB899 0621150008 P O dumpcheck The copy directory is too small.F89FB899 0620150008 P O dumpcheck The copy directory is too small.F89FB899 0619150008 P O dumpcheck The copy directory is too small.F89FB899 0618150008 P O dumpcheck The copy directory is too small.F89FB899 0617150008 P O dumpcheck The copy directory is too small.F89FB899 0616150008 P O dumpcheck The copy directory is too small.F89FB899 0615150008 P O dumpcheck The copy directory is too small.F89FB899 0614150008 P O dumpcheck The copy directory is too small.F89FB899 0613150008 P O dumpcheck The copy directory is too small.F89FB899 0612150008 P O dumpcheck The copy directory is too small.BFE4C025 0612045008 P H sysplanar0 UNDETERMINED ERRORBFE4C025 0612044908 P H sysplanar0 UNDETERMINED ERRORBFE4C025 0612044808 P H sysplanar0 UNDETERMINED ERRORBFE4C025 0612044108 P H sysplanar0 UNDETERMINED ERROR进入ORACLE用户，对ORACLE进行检查，发现ORACLE日志为：# su - oracleYOU HAVE NEW MAIL$ mailMail 5.2 UCB AIX 5.X Type ? for help./var/spool/mail/oracle: 13 messages 13 newN 1 daemon Thu Jun 26 01:01 31/906 Output from cron job /oradat N 2 daemon Fri Jun 27 01:01 31/906 Output from cron job /oradat N 3 daemon Sat Jun 28 01:01 31/906 Output from cron job /oradat N 4 daemon Sun Jun 29 01:01 31/906 Output from cron job /oradat N 5 daemon Mon Jun 30 01:01 31/906 Output from cron job /oradat N 6 daemon Tue Jul 1 01:01 31/904 Output from cron job /oradat N 7 daemon Wed Jul 2 01:01 31/904 Output from cron job /oradat N 8 daemon Thu Jul 3 01:01 31/904 Output from cron job /oradat N 9 daemon Fri Jul 4 01:01 31/904 Output from cron job /oradat N 10 daemon Sat Jul 5 01:01 31/904 Output from cron job /oradat N 11 daemon Sun Jul 6 01:01 31/904 Output from cron job /oradat N 12 daemon Mon Jul 7 01:01 31/904 Output from cron job /oradat N 13 daemon Tue Jul 8 01:01 31/904 Output from cron job /oradatMessage 1-13:From daemon Tue Jul 8 01:01:00 2008Date: Tue, 8 Jul 2008 01:01:00 +0800From: daemonTo: oracleSubject: Output from cron job /oradata/rman_incr.sh, oracleaodb, exit status 127 Cron Environment: SHELL = PATH=/usr/bin:/etc:/usr/sbin:/usr/ucb:/usr/bin/X11:/sbin:/usr/java14/jre/bin:/usr/java14/bin CRONDIR=/var/spool/cron/crontabs ATDIR=/var/spool/cron/atjobs LOGNAME=oracle HOME=/u01 Your cron job executed on aodb on Tue Jul 8 01:00:00 BEIST 200/oradata/rman_incr.sh produced the following output: /oradata/rman_incr.sh: rman: not found.有13条消息都是rman_incr.sh:没有执行。rman_incr.sh脚本是放在ORACEL用户下自动在每天1点钟运行。脚本如下：$ crontab -l0 1 * * 0 /oradata/rman_full.sh0 1 * * 1-6 /oradata/rman_incr.shrman_incr.sh:脚本如下：$ more rman_incr.shrman target / EOFrun allocate channel t1 type disk;backup incremental level 1 database format /u01/backup/level0_%d_%s_%p_%u.bak include current controlfile;backup archivelog all format /u01/backup/log_%d_%s_%p_%u.bak delete all input;release channel t1;exitEOF其中backup archivelog all format /u01/backup/log_%d_%s_%p_%u.bak delete all input;为备份结束后删除所有归档日志目录文件。因此总结故障原因为：因为rman_incr.sh没有执行， Oracle数据库采用日志归档模式，没自动删除归档日志，过段时间出现归档日志满，导致数据库归档日志空间满，出现数据库存运行异常，不能新建任务联接，而下面客户端不断进行server-to- client模式应用联接，导致系统ps的使用率达到了100%.因为ping的回复是net card直接响应，而telnet要系统开pid的，所以出现能PING通不能登录的故障现象。ps的100%一般是由于应用造成的,pid停了以后没有释放ps资源，所以现在在运行的pid会正常,但是无法再启用新的pid了,因为无法请求到资源。所以出故障原因为以联接上的ARIMS客户端能正常工作，而新开的客户端不能联接故障现象。解决故障办法： 修改rman_incr.sh脚本：增加ORACLE环境变量在脚本里，使之能找到rman命令，运行脚本，进行每天定期删除归档日志文件，清理空间，从而解决故障现象。$vi rman_incr.shPATH=/usr/bin:/etc:/usr/sbin:/usr/ucb:$HOME/bin:/usr/bin/X11:/sbin:/u01:.export PATHexport ORACLE_BASE=/u01/oracle/product/10.2.0export ORACLE_HOME=/u01/oracle/product/10.2.0/db_1export ORACLE_SID=tharimsexport PATH=$ORACLE_HOME/bin:$PATHLIBPATH=$LIBPATH:/usr/java14/jre/bin/classic:/usr/mqm/librman target / set inbound_connect_timeout 02、在sqlnet.ora文件中增加下一列参数：SQLNET.INBOUND_CONNECT_TIMEOUT=03、重新加载监听SQL $ lsnrctlLSNRCTL for 32-bit Windows: Version 10.2.0.1.0 - Production on 10-7月 -2008 01:56:33欢迎来到LSNRCTL, 请键入help以获得信息。LSNRCTL reload正在连接到 (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=EXTPROC1)命令执行成功LSNRCTL services正在连接到 (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=EXTPROC1)服务摘要.服务 PLSExtProc 包含 1 个例程。 例程 PLSExtProc, 状态 UNKNOWN, 包含此服务的 1 个处理程序. 处理程序: DEDICATED 已建立:0 已被拒绝:0 LOCAL SERVER服务 arims 包含 1 个例程。 例程 arims, 状态 READY, 包含此服务的 1 个处理程序. 处理程序: DEDICATED 已建立:0 已拒绝:0 状态:ready LOCAL SERVER服务 arimsXDB 包含 1 个例程。 例程 arims, 状态 READY, 包含此服务的 1 个处理程序. 处理程序: D000 已建立:0 已被拒绝:0 当前: 0 最大: 1002 状态: ready DISPATCHER (ADDRESS=(PROTOCOL=tcp)(HOST=flywolf)(PORT=2058)服务 arims_XPT 包含 1 个例程。 例程 arims, 状态 READY, 包含此服务的 1 个处理程序. 处理程序: DEDICATED 已建立:0 已拒绝:0 状态:ready LOCAL SERVER命令执行成功LSNRCTL show inbound_connect_timeout正在连接到 (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=EXTPROC1)LISTENER 参数 inbound_connect_timeout 设为 0命令执行成功LSNRCTL exitSQL现观察至7月15日，应用服务器双机监控程序在窗口已没有报错误提示。引用一段Oracle文档说明如下:SQLNET.INBOUND_CONNECT_TIMEOUTPurposeUse the SQLNET.INBOUND_CONNECT_TIMEOUT parameter to specify the time, in seconds, for a client to connect with the database server and provide the necessary authentication information.If the client fails to establish a connection and complete authentication in the time specified, then the database server terminates the connection. In addition, the database server logs the IP address of the client and an ORA-12170: TNS:Connect timeout occurred error message to the sqlnet.log file. The client receives either an ORA-12547: TNS:lost contact or an ORA-12637: Packet receive failed error message.Without this parameter, a client connection to the database server can stay open indefinitely without authentication. Connections without authentication can introduce possible denial-of-service attacks, whereby malicious clients attempt to flood database servers with connect requests that consume resources.To protect both the database server and the listener, Oracl