ORACLE中startup報錯的示例分析

這篇文章主要介紹ORACLE中startup報錯的示例分析，文中介紹的非常詳細，具有一定的參考價值，感興趣的小伙伴們一定要看完！

oracle數據庫無法通過遠程連接，連接報錯如圖：
操作系統：windows server2008 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報錯的示例分析”這篇文章的所有內容，感謝各位的閱讀！希望分享的內容對大家有幫助，更多相關知識，歡迎關注億速云行業資訊頻道！