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数据库服务、重启操作系统，如果不是这个顺序，就可能导致数据文件损坏，数据库启动需要恢复而打开过程很慢，需要耐心等待。