ORACLE startup报错之ORA-01154&&ORA-01155&&ORA-01033&&ORA-03113-阿里云开发者社区

今天，一实施同事求助，说一地市oracle数据库无法通过远程连接，连接报错如图：
操作系统：windows server 2008 R2
数据库版本：oracle 11.2.0.1

初看报错貌似数据库正处在打开或关闭的过程中。查看告警日志，最近的一次数据库启动发生在上午10:50，部分告警日志如下：
Wed Aug 02 10:51:48 2017
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 3
Wed Aug 02 10:52:01 2017
Autotune of undo retention is turned on.
IMODE=BR
ILAT =86
LICENSE_MAX_USERS = 0
SYS auditing is disabled
Starting up:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options.
然后，实施同事说，他中午那会startup了一下数据库，但是数据库停在了：“ 数据库装载完毕。”好长一段时间，如图：

然后，启动就报了ORA-03113，如果所示：

然后，他又说，数据库启动失败后，他接着重启了数据库服务器主机，然后但是问题依旧。
接下来是我的处理过程：
登录数据库服务器，
查看主机状态，CPU、磁盘IO、内存等资源很空闲
查看数据库服务和监听服务均已启动
登录数据库sqlplus查看数据库实例当前状态是mounted
Microsoft Windows [版本 6.1.7601]

版权所有 (c) 2009 Microsoft Corporation。保留所有权利。
C:\Users\Administrator>sqlplus / as sysdba
SQL*Plus: Release 11.2.0.1.0 Production on 星期三 8月 2 13:48:40 2017
Copyright (c) 1982, 2010, Oracle. All rights reserved.
连接到:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL> select status from v$instance;
STATUS
------------
MOUNTED
--尝试open数据库报ORA-01154，日志如下：
SQL> alter database open;
alter database open
*
第 1 行出现错误:
ORA-01154: 数据库忙。现在不允许打开, 关闭, 装载和卸装

接下来，重启了操作系统的Oracle实例服务，然后重新启动，启动依然停留在“ 数据库装载完毕”，日志如下：
从 Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options(情况复杂) 断开
C:\Users\Administrator>sqlplus / as sysdba
SQL*Plus: Release 11.2.0.1.0 Production on 星期三 8月 2 13:58:58 2017
Copyright (c) 1982, 2010, Oracle.  All rights reserved.
已连接到空闲例程。
SQL> startup
ORACLE 例程已经启动。
Total System Global Area 2.0577E+10 bytes
Fixed Size                  2184672 bytes
Variable Size            8589937184 bytes
Database Buffers         1.1945E+10 bytes
Redo Buffers               39743488 bytes
数据库装载完毕。
--观察数据库告警日志，12:59分数据库有ORA-00949，有实例进程超时等待
Wed Aug 02 12:59:29 2017
Errors in file d:\oraclehome\oracle\diag\rdbms\bmi\bmi\trace\bmi_arc1_3604.trc (incident=164377):
ORA-00494: 持有入队 [CF] 的时间过长 (超过 900 秒) (由 'inst 1, osid 3084')
Incident details in: d:\oraclehome\oracle\diag\rdbms\bmi\bmi\incident\incdir_164377\bmi_arc1_3604_i164377.trc
Killing enqueue blocker (pid=3084) on resource CF-00000000-00000000 by (pid=3604)
by killing session 638.1
Killing enqueue blocker (pid=3084) on resource CF-00000000-00000000 by (pid=3604)
by terminating the process
ARC1 (ospid: 3604): terminating the instance due to error 2103
--13:20数据库被重启，日志如下（猜想是主机重启后的自动重启）
Wed Aug 02 13:19:29 2017
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 3
Autotune of undo retention is turned on.
IMODE=BR
ILAT =86
LICENSE_MAX_USERS = 0
SYS auditing is disabled
Starting up:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options.
--观察到TNS连接报错： ORA-01155
Wed Aug 02 13:34:35 2017
Errors in file d:\oraclehome\oracle\diag\rdbms\bmi\bmi\trace\bmi_m000_4620.trc:
ORA-01155: 正在打开, 关闭, 装载或卸装数据库
Wed Aug 02 13:48:39 2017
TNS-12535: TNS: 操作超时
ns secondary err code: 12606
nt main err code: 0
nt secondary err code: 0
nt OS err code: 0
Client address: (ADDRESS=(PROTOCOL=tcp)(HOST=fe80::94b2:4372:a24c:4b6e%11)(PORT=49179))
WARNING: inbound connection timed out (ORA-3136)
Wed Aug 02 13:49:38 2017
Errors in file d:\oraclehome\oracle\diag\rdbms\bmi\bmi\trace\bmi_m000_5596.trc:
ORA-01155: 正在打开, 关闭, 装载或卸装数据库
再看自己重启后的告警日志
Wed Aug 02 13:59:07 2017
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 3
Autotune of undo retention is turned on.
IMODE=BR
ILAT =86
LICENSE_MAX_USERS = 0
SYS auditing is disabled
Starting up:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options.
......
Wed Aug 02 13:59:12 2017
ALTER DATABASE MOUNT
Wed Aug 02 13:59:12 2017
MMNL started with pid=17, OS id=2012
Successful mount of redo thread 1, with mount id 271372528
Database mounted in Exclusive Mode
Lost write protection disabled
Completed: ALTER DATABASE MOUNT
Wed Aug 02 13:59:17 2017
ALTER DATABASE OPEN
Beginning crash recovery of 1 threads
parallel recovery started with 15 processes
Wed Aug 02 13:59:41 2017
Started redo scan
Wed Aug 02 14:01:55 2017
Completed redo scan
read 8951211 KB redo, 764700 data blocks need recovery
Wed Aug 02 14:03:22 2017
Started redo application at
Thread 1: logseq 364892, block 508132
Recovery of Online Redo Log: Thread 1 Group 7 Seq 364892 Reading mem 0
Mem# 0: D:\ORACLEHOME\ORACLE\ORADATA\BMI\REDO07_01.LOG
Mem# 1: D:\ORACLEHOME\ORACLE\ORADATA\BMI\REDO07_02.LOG
Recovery of Online Redo Log: Thread 1 Group 21 Seq 364893 Reading mem 0
Mem# 0: D:\ORACLEHOME\ORACLE\ORADATA\BMI\REDO21_01.LOG
Mem# 1: D:\ORACLEHOME\ORACLE\ORADATA\BMI\REDO21_02.LOG
从启动告警日志可以看到，数据库肯定被异常终止过，当前数据库增在从redo日志恢复，此时需要耐心等待；再次询问实施同事并让其关闭远程的所有oracle客户端程序。
然后等待20分钟，数据库完成了open操作
Wed Aug 02 14:19:19 2017
Completed crash recovery at
Thread 1: logseq 364905, block 820661, scn 14976863197959
764700 data blocks read, 474332 data blocks written, 8951211 redo k-bytes read
Wed Aug 02 14:19:37 2017
LGWR: STARTING ARCH PROCESSES
Wed Aug 02 14:19:37 2017
ARC0 started with pid=37, OS id=1072
ARC0: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC0: STARTING ARCH PROCESSES
Wed Aug 02 14:19:38 2017
ARC1 started with pid=38, OS id=5408
Wed Aug 02 14:19:38 2017
ARC2 started with pid=39, OS id=4412
ARC1: Archival started
ARC2: Archival started
ARC2: Becoming the 'no FAL' ARCH
ARC2: Becoming the 'no SRL' ARCH
ARC1: Becoming the heartbeat ARCH
Wed Aug 02 14:19:38 2017
ARC3 started with pid=40, OS id=5536
ARC3: Archival started
ARC0: STARTING ARCH PROCESSES COMPLETE
Thread 1 advanced to log sequence 364906 (thread open)
Thread 1 opened at log sequence 364906
Current log# 6 seq# 364906 mem# 0: D:\ORACLEHOME\ORACLE\ORADATA\BMI\REDO06_01.LOG
Current log# 6 seq# 364906 mem# 1: D:\ORACLEHOME\ORACLE\ORADATA\BMI\REDO06_02.LOG
Successful open of redo thread 1
Wed Aug 02 14:19:45 2017
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Wed Aug 02 14:19:45 2017
SMON: enabling cache recovery
Successfully onlined Undo Tablespace 2.
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is ZHS16GBK
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Wed Aug 02 14:20:02 2017
Starting background process QMNC
Wed Aug 02 14:20:02 2017
QMNC started with pid=58, OS id=5700
Completed: ALTER DATABASE OPEN
--在数据库open的过程中，本地登录sqlplus查看会话信息，数据库确实开启了并行进程恢复：
SQL> select sid,process,program from v$session
2 where
3 type = 'USER'
4 and
5 SID not in (select DISTINCT SID from v$mystat);

SID PROCESS PROGRAM
---------- ------------------------ ----------------------------------------------------------------
3 3668 ORACLE.EXE (P011)
4 828 ORACLE.EXE (P022)
51 6024 ORACLE.EXE (P012)
52 5824 ORACLE.EXE (P023)
100 5880 ORACLE.EXE (P013)
101 4624 ORACLE.EXE (P024)
148 6048 ORACLE.EXE (P014)
150 2452 ORACLE.EXE (P025)
198 6028 ORACLE.EXE (P000)
200 3060 ORACLE.EXE (P026)
251 4844 ORACLE.EXE (P027)
298 4556 ORACLE.EXE (P001)
299 4356 ORACLE.EXE (P028)
347 4828 ORACLE.EXE (P002)
348 5956 ORACLE.EXE (P029)
396 5716 ORACLE.EXE (P003)
397 4288 ORACLE.EXE (P030)
443 5992 ORACLE.EXE (P004)
444 2828 ORACLE.EXE (P015)
445 4140 ORACLE.EXE (P031)
492 4704 ORACLE.EXE (P005)
493 5840 ORACLE.EXE (P016)
541 6004 ORACLE.EXE (P006)
542 2216 ORACLE.EXE (P017)
590 5048 ORACLE.EXE (P018)
591 1808 ORACLE.EXE (P007)
639 5632 ORACLE.EXE (P019)
640 4936 ORACLE.EXE (P008)
641 4436 ORACLE.EXE (J000)
689 5576 ORACLE.EXE (P020)
690 5884 ORACLE.EXE (P009)
737 6064 ORACLE.EXE (P021)
739 6012 ORACLE.EXE (P010)
已选择33行。

数据库完成open后查看数据库状态，数据库恢复正常：
SQL> startup
ORACLE 例程已经启动。
Total System Global Area 2.0577E+10 bytes
Fixed Size 2184672 bytes
Variable Size 8589937184 bytes
Database Buffers 1.1945E+10 bytes
Redo Buffers 39743488 bytes
数据库装载完毕。
数据库已经打开。
SQL> select instance_name,status from v$instance;
INSTANCE_NAME STATUS
---------------- ------------
bmi OPEN
SQL>

SQL> select name,open_mode from v$database;
NAME OPEN_MODE
--------- --------------------
BMI READ WRITE
SQL>

注意：本次故障中，需要实施同事明白Oracle数据库的启动和关闭过程；重启操作系统前，需要先关闭oracle监听、确定当前数据库中没有执行计划任务或存储过程、
关闭oracle数据库实例、关闭oracle数据库服务、重启操作系统，如果不是这个顺序，就可能导致数据文件损坏，数据库启动需要恢复而打开过程很慢，需要耐心等待。

ORACLE startup报错之ORA-01154&&ORA-01155&&ORA-01033&&ORA-03113

热门文章

最新文章

相关电子书

推荐镜像