天道酬勤

今天我的虚拟测试环境中的11.2的库自上次关机后今天启动突然报错，记录以下过程备查。

1
2
3
4
5
6
7
8
9

SQL> SELECT * FROM v$version;
 
BANNER
--------------------------------------------------------------------------------
Oracle DATABASE 11g Enterprise Edition RELEASE 11.2.0.2.0 - 64bit Production
PL/SQL RELEASE 11.2.0.2.0 - Production
CORE    11.2.0.2.0      Production
TNS FOR Linux: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production

启动数据库时报错：

1
2
3
4
5
6
7
8
9

SQL> startup
ORACLE instance started.
 
Total SYSTEM Global Area  734892032 bytes
Fixed SIZE                  2230120 bytes
Variable SIZE             448792728 bytes
DATABASE Buffers          276824064 bytes
Redo Buffers                7045120 bytes
ORA-00205: error IN identifying control FILE, CHECK alert LOG FOR more info

根据alert log找到trace文件：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26

[oracle@ORCL112 ~]$ more /u01/app/oracle/diag/rdbms/orcl112/orcl112/trace/orcl112_asmb_6745.trc
Trace FILE /u01/app/oracle/diag/rdbms/orcl112/orcl112/trace/orcl112_asmb_6745.trc
Oracle DATABASE 11g Enterprise Edition RELEASE 11.2.0.2.0 - 64bit Production
WITH the Partitioning, OLAP, Data Mining AND REAL Application Testing options
ORACLE_HOME = /u01/app/oracle/product/11.2.0/dbhome_1
SYSTEM name:    Linux
Node name:      ORCL112
RELEASE:        2.6.18-92.el5
Version:        #1 SMP Fri May 23 23:40:43 EDT 2008
Machine:        x86_64
VM name:        VMWare Version: 6
Instance name: orcl112
Redo thread mounted BY this instance: 0 <none>
Oracle process NUMBER: 16
Unix process pid: 6745, image: oracle@ORCL112 (ASMB)
 
*** 2011-11-10 12:42:57.949
*** SESSION ID:(8.1) 2011-11-10 12:42:57.950
*** CLIENT ID:() 2011-11-10 12:42:57.950
*** SERVICE NAME:() 2011-11-10 12:42:57.950
*** MODULE NAME:() 2011-11-10 12:42:57.950
*** ACTION NAME:() 2011-11-10 12:42:57.950
 
WARNING: failed TO START ASMB (connection failed) state=0x1 sid='+ASM' home='/u01/app/grid/product/11.2.0/grid'
ORA-15055: unable TO CONNECT TO ASM instance
ORA-12547: TNS:lost contact

1
2
3
4
5

[grid@ORCL112 ~]$ crsctl stat res -t
--------------------------------------------------------------------------------
NAME           TARGET  STATE        SERVER     STATE_DETAILS   Local Resources
ora.DG01.dg    ONLINE  ONLINE       orcl112                         
ora.asm        ONLINE  ONLINE       orcl112     Started

MOS上有相关文档：[ID 1307075.1]
是由于$GRID_HOME/bin/oracle和$ORACLE_HOME/bin/oracle文件权限不当导致连接ASM实例失败的。
ls -al $GRID_HOME/bin/oracle
-rwxr-x--x 1 grid oinstall 200678464 Feb 28 14:54 oracle
 
ls -al $ORACLE_HOME/bin/oracle
-rwxr-x--x 1 oracle asmadmin 228886191 Feb 28 15:41 oracle 
而在我的环境中只有$GRID_HOME/bin/oracle文件权限发生改变
[grid@ORCL112 bin]$ cd /u01/app/grid/product/11.2.0/grid/bin
[grid@ORCL112 bin]$ ls -l oracle
-rwxrwxr-x 1 grid oinstall 200678464 Jul 15 23:18 oracle

解决方法很简单：
oracle binary的正确权限是：6751
cd $GRID_HOME/bin
chmod 6751 oracle
 
cd $ORACLE_HOME/bin
chmod 6751 oracle
修改之后再检查一下
ls -l oracle
-rwsr-s--x 1 grid oinstall 152400480 Nov 24 15:49 oracle
如果数据库启动仍然失败，重新启动GI

修改之后数据库正常启动
[root@ORCL112 bin]# chmod 6751 oracle
[root@ORCL112 bin]# ls -l oracle
-rwsr-s--x 1 grid oinstall 200678464 Jul 15 23:18 oracle
SQL> startup
ORACLE instance started.
 
Total SYSTEM Global Area  734892032 bytes
Fixed SIZE                  2230120 bytes
Variable SIZE             448792728 bytes
DATABASE Buffers          276824064 bytes
Redo Buffers                7045120 bytes
DATABASE mounted.
DATABASE opened.

-The End-

最近公司有一个ERP的项目，客户选用Oracle E-Business Suit R12。在这之前我从未使用过任何ERP软件，既然这样，最好的办法就是自己搭建一个环境感受一下。

昨天通宵恢复一个1T的数据库，早上6点成功恢复，立即开始备份。7点回家睡觉下午三点起床，也许这就是一个DBA的生活。本想现在写写恢复过程，不过又想睡觉了，明天好好写吧。

Updated  @ 2010-12-07

一、系统背景：

硬件：    P690_1和P670_1

操作系统：A IX 5.2 ML04

数据库：  Oracle 9.2.0.1.0  2 Nodes RAC  HA

备库P570（非DG）： 与DG原理类似，利用生产库的归档日志在P570上恢复

故障时间：2010-11-23  13:20

二、故障现象：

数据库系统在13：19报告SYSTEM表空间空间不够无法自动扩展，因为系统使用RAW设备所以无法自动扩展，需要管理员手工增加RAW设备文件。

客户工程师在P670_1节点上新增RAW设备并增加到SYSTEM表空间：

RAW设备：/dev/rwwwdb_system04

SQL>alter tablespace system add ‘/dev/rwwwdb_system04’ reuse;

随后系统报错：

dbv检查数据文件，报文件坏块：

此时，由于系统表空间不足数据库系统被挂起，欲将增加失败的数据文件离线删除后重启数据库实例报错：

SQL>ALTER DATABASE DATAFILE ‘/dev/rwwwdb_system04′ offline drop;

不要受[ID 422031.1]ORA-01122, ORA-01251 or data blocks reported as corrupted影响，否则方向错了会花比较多的时间

时间：16：00

由于系统数据量大，在生产库不能短时间恢复情况下的

措施：启动P570备库

结果：启动备库P570失败

原因：在10月19增加数据库文件/dev/rphoto1026时出错，需要恢复。

时间：16：20

措施：利用生产系统RMAN备份来恢复

结果：无法恢复

原因：每晚8点的定时备份任务在14日由于备份空间不足备份失败，后续没有任务备份；系统归档日志保留策略为7天，若要恢复到14日备份前，缺少1天的归档日志文件。

Read the rest of this entry »

上周四中午刚放下订餐电话，手机响起鸟，客户的一套AIX 5.2 ML04  +  Oracle 10.2.0.3.0 (+Dataguard)的系统挂了，业务中断。收拾东西下楼打车赶往客户机房，大致半小时后到达客户机房登录系统检查发现系统报：“ORA-00600: internal error code, arguments: [2103], [1], [0], [1], [900]”错误。[2103]的错误与controlfile有关，[900]是等待的超时时间S。进一步检查发现，问题是出现在每天晚上0点都有crontab调度的系统备份任务：0点将系统置为热备模式—>连接FTP服务器—>CP需要备份的所有件—>最后将系统退出热备模式。metalink [ID 567891.1]说：系统处在热备份模式下，在日志发生切换时获取控制文件队列信息时发生了超时，这个等待时间默认是15分钟（900s）。虽然这里有一个Bug 6018274，但我的习惯是只有在做完了尽可能的尝试之后再认为是bug。

继续检查发现，系统一直在进行kill动作：“Killing enqueue blocker (pid=827572) on resource CF-00000000-00000000”，但遗憾的是这个动作失败了，尝试手工kill，失败。而且此时在系统中只要一发起与log相关的动作系统就挂起，无赖之下想重启oracle(这个想法很邪恶啊，如果待会儿起不来，how?),FT……正常关闭失败（意料中的），abort关机失败，回到OS中kill -9失败。万般无赖之下，只能重启OS，没想到的是AIX重启到一般的时候挂起，此时已经13：30了，还没有吃饭（12点客户叫俺一起去吃饭看到她那表情俺也有点不好意思。）不管了，先搞定系统再说吧。由于这套系统是P690上的一个分区，只要在HMC上使用“Hard Reset”选项了，鼠标移到此分区上检查了又检查了，俺视力5.2的说，但就怕这时看错了的话，后果，你知道的。在这前后几分钟，真有心跳加速的感觉，就怕待会儿库打不开啊。10分钟之后，my god，库顺利的打开了，哎呀，肚子不饿了，起应用一切顺利，先让别人开工吧。

造成ORA-00600 [2103]错误的原因有下：

1) 控制文件存放在I/O非常慢的存储系统上。

2) 频繁的日志切换，或日志文件过小或日志文件组数目过少。

3) 同时使用了异步I/O或多个数据写进程。

4) Oracle软件内部Bug。

5) OS/硬件问题。

讯问过客户工程师，确实在前一天18：30的时候进行数据整理，发生过非常频繁的日志切换，高峰时1分钟达5次日志切换，但在其后一天是正常的，由于环境复杂，暂时先做如下测试：（以影响业务程度最小化且实施难易程度依次列出）

1. 增大日志组成员大小，同时增加日志组数目。

2. 由于业务的特殊性，商讨能否修改备份策略来避开热备份。

3. 根据官方建议打补丁：Patch 5923866，在失效的情况下，将系统升级到10.2.0.4.0之上（最新分布为10.2.0.5.0）

4. 将操作系统从AIX 5.2 ML04升级到AIX 5.2 ML05（Oracle在[ID 406191.1]中建议）

BTW：在我重启完系统后问客户，此套系统应该有Dataguard的吧，答案是肯定的。到这里，可能大家会说为什么不在出问题的时候将系统切换到备机上。其实切换系统更多决定因素不仅仅只在技术层面的。

-The End-