一次支付平台紧急故障处理备忘
作者：田逸（sery@163.com）
监控没报警直接收到故障电话，说业务全部挂了。时间紧迫，需要快速解决。
根据拓扑结构，顺序进行如下操作：
◎检查负载均衡器
负载均衡器安装keepalived + haproxy，先从监控界面检查运行状态，其输出如下图所示
由图可知，还有一个应用处于正常状态，因此可以大致判定负载均衡应该是正常的。
◎检查应用服务器
应用服务器由4个服务器组成2组独立的集群，每组服务器安装的软件和配置完全一样。因此，每组服务器只需要检查其中的一个服务器就可以了。登录系统，检查如下项目：
1、 检查进程，查看tomcat是否还在运行，执行指令 ps auxww | grep java ，两个java进程运行得好好的呢！
2、 检查网络状态，分别执行 netstat –anp | grep EST ，也看不出有什么异常。
3、 检查tomcat日志，发现一段可疑输出，片段截取如下：
|
Could not open JDBC Connection for transaction; nested exception is java.sql.SQLException: An attempt by a client to checkout a Connection has timed out. |
问了其他技术人员，回答说今天没有做任何程序方面的修改，由此可以简单断定，可能是数据库出了问题。顺手在应用服务上测试一下数据库服务器的网络联通性，执行命令ping 172.16.5.40,正常；再执行 telnet 172.16.5.41 1521 有正常的输出，这可以确定数据库的监听也是启动的。注意：oracle rac监听地址是安装过程中设定的vip，而不是实际物理接口地址，这就是什么啥ping的地址是172.16.5.40，而telnet 跟的地址是172.16.5.41的原因。
4、 重启一下tomcat，故障依旧。
5、 检查系统日志，无可以信息发现。
6、 直接在浏览器输入应用服务器的可访问url，异常。
◎检查数据库服务器
◆系统方面的检查
1、检查oracle相关进程，ps aux ，其输出片段为
相关进程都处于运营状态。
◆检查监听器
|
[oracle@db40 ~]$ lsnrctl status
LSNRCTL for Linux: Version 11.2.0.1.0 - Production on 29-6月 -2014 10:02:49
Copyright (c) 1991, 2009, Oracle. All rights reserved.
Connecting to (ADDRESS=(PROTOCOL=tcp)(HOST=)(PORT=1521)) STATUS of the LISTENER ------------------------ Alias LISTENER Version TNSLSNR for Linux: Version 11.2.0.1.0 - Production Start Date 09-5月 -2014 17:42:24 Uptime 50 days 16 hr. 20 min. 33 sec Trace Level off Security ON: Local OS Authentication SNMP OFF Listener Parameter File /u01/app/grid/network/admin/listener.ora Listener Log File /u01/app/oracle/diag/tnslsnr/db40/listener/alert/log.xml Listening Endpoints Summary... (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=LISTENER))) (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=127.0.0.1)(PORT=1521))) (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=172.16.5.41)(PORT=1521))) Services Summary... Service "+ASM" has 1 instance(s). Instance "+ASM1", status READY, has 1 handler(s) for this service... Service "zyzf" has 1 instance(s). Instance "zyzf1", status READY, has 1 handler(s) for this service... Service "zyzfXDB" has 1 instance(s). Instance "zyzf1", status READY, has 1 handler(s) for this service... The command completed successfully |
ASM实例及服务在监听器里注册状态都是正常的。
◆检查asm
执行如下指令进行简单判断
|
[root@db50 ~]# su - grid [grid@db50 ~]$ asmcmd ASMCMD> ls DATA/ FLASH/ OCR/ ASMCMD> cd FLASH ASMCMD> ls ZYZF/ ASMCMD> cd ZYZF ASMCMD> ls ARCHIVELOG/ BACKUPSET/ ASMCMD> cd ARC* ASMCMD> ls 2014_06_29/ |
看来问题不在这里。
◆检查数据库实例
本地登录登录oracle客户端，说起来好专业，实际上就是执行sqlplus嘛。进行的操作记录如下：
|
[oracle@db50 ~]$ sqlplus / as sysdba
SQL*Plus: Release 11.2.0.1.0 Production on ??? 6? 29 12:01:47 2014
Copyright (c) 1982, 2009, Oracle. All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP, Data Mining and Real Application Testing options
SQL> select count(*) from v$process;
COUNT(*) ---------- 41
SQL> select count(*) from v$session;
COUNT(*) ---------- 37 |
明明有连接嘛，看来问题不大。
◆检查oracle报警日志
在数据实例报警文件，发现如下有用信息：
|
client_id='' type='UNKNOWN' level='16' host_id='db50' host_addr='127.0.0.1' module='' pid='5671'>
client_id='' type='UNKNOWN' level='16' host_id='db50' host_addr='127.0.0.1' module='' pid='5671'>
ORA-19809: limit exceeded for recovery files ORA-19804: cannot reclaim 50331648 bytes disk space from 42967498752 limit
client_id='' type='UNKNOWN' level='16' host_id='db50' host_addr='127.0.0.1' module='' pid='5671'>
|
既然你说问题记录在文件/u01/app/oracle/diag/rdbms/zyzf/zyzf2/trace/zyzf2_arc2_5671.trc，咱就乖乖听你的，打开文件看一下也无妨,打开一看，确实有用哟，其部分输出如下：
|
*** 2014-06-27 21:45:03.674 2046 krse.c Archived Log entry 770 added for thread 2 sequence 250 ID 0x1bcb54de dest 1: +FLASH/zyzf/archivelog/2014_06_27/thread_2_seq_250.443. 851377503 *** 2014-06-28 10:05:32.844 2046 krse.c
*** 2014-06-28 10:05:32.844 Archived Log entry 782 added for thread 2 sequence 253 ID 0x1bcb54de dest 1: +FLASH/zyzf/archivelog/2014_06_28/thread_2_seq_253.546. 851421933 *** 2014-06-28 13:18:07.129 2046 krse.c
*** 2014-06-28 13:18:07.129 Archived Log entry 795 added for thread 2 sequence 256 ID 0x1bcb54de dest 1: +FLASH/zyzf/archivelog/2014_06_28/thread_2_seq_256.654. 851433487 *** 2014-06-28 14:41:21.362 2046 krse.c |
原来是归档日志轮转的时候，没空间可以创建文件了。
◎故障处理
查明原因，因时间紧迫，需立即处理。过程记录如下：
◆检查闪回恢复区（为啥查它？因为归档日志在这里啊！）
|
SQL> show parameter db_recovery_file_dest
NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ db_recovery_file_dest string +FLASH db_recovery_file_dest_size big integer 40977M |
总共40G，看一下实际用了多少？
|
SQL> select FILE_TYPE,PERCENT_SPACE_USED from v$flash_recovery_area_usage;
FILE_TYPE PERCENT_SPACE_USED -------------------- ------------------ CONTROL FILE 0 REDO LOG 0 ARCHIVED LOG 97.75 BACKUP PIECE 1.16 IMAGE COPY 0 FLASHBACK LOG 0 FOREIGN ARCHIVED LOG 0
7 rows selected. |
◆删除归档日志
Rman target /
Delete archivelog all;
全部干掉。
再查看报警日志，开始有新的归档生成的记录：
|
client_id='' type='UNKNOWN' level='16' host_id='db50' host_addr='127.0.0.1' module='' pid='5538'>
client_id='' type='UNKNOWN' level='16' host_id='db50' host_addr='127.0.0.1' module='' pid='5671'>
|
从应用层面进行访问，一切都正常了。
补充：后边得把监控完善，再弄个计划任务，做好备份或者直接定期清理陈旧的归档日志。