繼續上篇的tab$被清空(ORA-600 16703故障解析—tab$表被清空),導致數據庫啟動異常的case
ORA-600 16703報錯
數據庫日志分析
數據庫open成功同時報ORA-7445 kokeicbegin和ORA-600 kzrini:!uprofile錯誤
這里有一個其他現象,就是數據庫在open成功的同時(同一秒內),開始報異常.重啟之后直接報
ORA-00704: bootstrap process failure
ORA-00704: bootstrap process failure
ORA-00600: internal error code, arguments: [16703], [1403], [20], [], [], [], [], [], [], [], [], []
根據10046分析結果
===================== select rowcnt,blkcnt,empcnt,avgspc,chncnt,avgrln,nvl(degree,1), nvl(instances,1) from tab$ where obj# = :1 END OF STMT PARSE #140048443935120:c=0,e=390,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1499185905161433 ===================== select blevel, leafcnt, distkey, lblkkey, dblkkey, clufac, nvl(degree,1), nvl(instances,1) from ind$ where bo# = :1 and obj# = :2 END OF STMT PARSE #140048443934176:c=1000,e=601,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1499185905162088 ===================== PARSING IN CURSOR #140048443933232 len=70 dep=1 uid=0 oct=3 lid=0 tim=1499185905162444 hv=3377894161 ad='84f13d70' sqlid='32d4jrb4pd4sj' select charsetid, charsetform from col$ where obj# = :1 and col# = :2 END OF STMT PARSE #140048443933232:c=0,e=294,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1499185905162443 ===================== PARSING IN CURSOR #140048443932288 len=52 dep=1 uid=0 oct=3 lid=0 tim=1499185905247020 hv=429618617 ad='84f0f2d0' sqlid='4krwuz0ctqxdt' select ctime, mtime, stime from obj$ where obj# = :1 END OF STMT PARSE #140048443932288:c=0,e=549,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1499185905247019 BINDS #140048443932288: select blevel, leafcnt, distkey, lblkkey, dblkkey, clufac, nvl(degree,1), nvl(instances,1) from ind$ where bo# = :1 and obj# = :2 END OF STMT PARSE #140048443934176:c=1000,e=601,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1499185905162088 ===================== PARSING IN CURSOR #140048443933232 len=70 dep=1 uid=0 oct=3 lid=0 tim=1499185905162444 hv=3377894161 ad='84f13d70' sqlid='32d4jrb4pd4sj' select charsetid, charsetform from col$ where obj# = :1 and col# = :2 END OF STMT PARSE #140048443933232:c=0,e=294,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1499185905162443 ===================== PARSING IN CURSOR #140048443932288 len=52 dep=1 uid=0 oct=3 lid=0 tim=1499185905247020 hv=429618617 ad='84f0f2d0' sqlid='4krwuz0ctqxdt' select ctime, mtime, stime from obj$ where obj# = :1 END OF STMT PARSE #140048443932288:c=0,e=549,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1499185905247019 BINDS #140048443932288: Bind#0 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=00 fl2=0001 frm=00 csi=00 siz=24 off=0 kxsbbbfp=7f5f91b87bd0 bln=22 avl=02 flg=05 value=20 EXEC #140048443932288:c=2000,e=2686,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=1218588913,tim=1499185905249810 WAIT #140048443932288: nam='db file sequential read' ela= 6205 file#=1 block#=337 blocks=1 obj#=36 tim=1499185905256132 WAIT #140048443932288: nam='db file sequential read' ela= 3739 file#=1 block#=338 blocks=1 obj#=36 tim=1499185905266704 WAIT #140048443932288: nam='db file sequential read' ela= 4966 file#=1 block#=241 blocks=1 obj#=18 tim=1499185905271761 FETCH #140048443932288:c=0,e=21976,p=3,cr=3,cu=0,mis=0,r=1,dep=1,og=4,plh=1218588913,tim=1499185905271820 STAT #140048443932288 id=1 cnt=1 pid=0 pos=1 obj=18 op='TABLE ACCESS BY INDEX ROWID OBJ$ (cr=3 pr=3 pw=0 time=21993 us)' STAT #140048443932288 id=2 cnt=1 pid=1 pos=1 obj=36 op='INDEX RANGE SCAN I_OBJ1 (cr=2 pr=2 pw=0 time=16923 us)' CLOSE #140048443932288:c=0,e=63,dep=1,type=0,tim=1499185905271941 BINDS #140048443935120: Bind#0 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0 kxsbbbfp=7f5f91c07de8 bln=22 avl=02 flg=05 value=20 EXEC #140048443935120:c=1000,e=795,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=2970138452,tim=1499185905272802 WAIT #140048443935120: nam='db file sequential read' ela= 3197 file#=1 block#=169 blocks=1 obj#=3 tim=1499185905276069 WAIT #140048443935120: nam='db file sequential read' ela= 3459 file#=1 block#=170 blocks=1 obj#=3 tim=1499185905404084 WAIT #140048443935120: nam='db file sequential read' ela= 6358 file#=1 block#=145 blocks=1 obj#=4 tim=1499185905410548 FETCH #140048443935120:c=999,e=137805,p=3,cr=3,cu=0,mis=0,r=0,dep=1,og=4,plh=2970138452,tim=1499185905410635 STAT #140048443935120 id=1 cnt=0 pid=0 pos=1 obj=4 op='TABLE ACCESS CLUSTER TAB$ (cr=3 pr=3 pw=0 time=137810 us)' STAT #140048443935120 id=2 cnt=1 pid=1 pos=1 obj=3 op='INDEX UNIQUE SCAN I_OBJ# (cr=2 pr=2 pw=0 time=131330 us)' *** 2017-07-05 00:31:46.094 Incident 176395 created, dump file: /oracle/diag/rdbms/orcl/orcl2/incident/incdir_176395/orcl_ora_51261_i176395.trc ORA-00600: internal error code, arguments: [16703], [1403], [20], [], [], [], [], [], [], [], [], []
以及以往恢復經驗和mos,基本上可以確定是由於tab$和obj$記錄不匹配導致該問題.而且是obj#=20的記錄在tab$和obj$中不匹配.
分析tab$和obj$記錄
Data UnLoader: 11.2.0.1.5 - Internal Only - on Wed Jul 05 01:28:53 2017 with 64-bit io functions and the decompression option Copyright (c) 1994 2017 Bernard van Duijnen All rights reserved. Strictly Oracle Internal Use Only Found db_id = 1334610369 Found db_name = orcl DUL> unload table TAB$( OBJ# number, DATAOBJ# number, 2 TS# number, FILE# number, BLOCK# number, 3 BOBJ# number, TAB# number, COLS number, CLUCOLS number, 4 PCTFREE$ ignore, PCTUSED$ ignore, INITRANS ignore, MAXTRANS ignore, 5 FLAGS ignore, AUDIT$ ignore, ROWCNT ignore, BLKCNT ignore, 6 EMPCNT ignore, AVGSPC ignore, CHNCNT ignore, AVGRLN ignore, 7 AVGSPC_FLB ignore, FLBCNT ignore, 8 ANALYZETIME ignore, SAMPLESIZE ignore, 9 DEGREE ignore, INSTANCES ignore, 10 INTCOLS ignore, KERNELCOLS number, PROPERTY number) 11 cluster C_OBJ#(OBJ#) 12 storage ( tablespace 0 segobjno 2 tabno 1 file 1 block 144); . unloading table TAB$ 0 rows unloaded DUL> unload table OBJ$( OBJ# number, DATAOBJ# number, OWNER# number, 2 NAME clean varchar2(30), NAMESPACE ignore, SUBNAME clean varchar2(30), 3 TYPE# number, CTIME ignore, MTIME ignore, STIME ignore, 4 STATUS ignore, REMOTEOWNER ignore, LINKNAME ignore, 5 FLAGS ignore, OID$ hexraw) 6 storage ( tablespace 0 segobjno 18 file 1 block 240); . unloading table OBJ$ 89804 rows unloaded DUL>
這里可以明確表示tab$無記錄,obj$有記錄,從而啟動的過程出現ORA-600 16703錯誤可以很好解釋.由於數據庫啟動成功和報錯幾乎同時進行,以及上面看到的tab$記錄不存在的情況,初步懷疑是有startup觸發器清空tab$表記錄
工具分析觸發器表trigger$
這里果然看到一個after startup on database的觸發器,名字為DBMS_SUPPORT_DBMONITOR,而它調用的是DBMS_SUPPORT_DBMONITORP存儲.
工具分析pl/sql表source$
這里可以明確的看到DBMS_SUPPORT_DBMONITORP存儲過程備份tab$表到orachk中然后delete tab$表,現在已經明確是由於DBMS_SUPPORT_DBMONITOR觸發器在數據庫重啟之后開始執行調用DBMS_SUPPORT_DBMONITORP程序,如果判斷數據庫創建時間大於等於300天,便干掉tab$表,實現數據庫破壞.
查找DBMS_SUPPORT_DBMONITOR等程序源頭
分析相關程序創建時間,通過obj$表的ctime和name來判斷
這里可以看出來DBMS_SUPPORT_DBMONITOR和DBMS_SUPPORT_DBMONITORP的創建時間基本上和數據庫核心對象的創建時間相差無幾,我們可以大概排除掉,是由於pl sql等工具連接數據庫導致該發問題(類似:plsql dev引起的數據庫被黑勒索比特幣實現原理分析和解決方案),很可能是在dbca創建庫的過程中就已經帶有了DBMS_SUPPORT_DBMONITOR等程序,如果這樣那很可能是由於數據庫的安裝介質被破壞導致該問題.
分析DBMS_SUPPORT_DBMONITOR來源
這里已經很清晰,由於prvtsupp.plb被人注入了惡意腳本從而使得數據庫被創建了DBMS_SUPPORT_DBMONITOR的觸發器和DBMS_SUPPORT_DBMONITORP的存儲過程,從而實現了對數據庫的而易破壞.
確定破壞文件prvtsupp.plb來源於介質
這里比較明顯,文件就是來源database\stage\Components\oracle.rdbms.dbscripts\11.2.0.4.0\1\DataFiles\filegroup2.jar\rdbms\admin\prvtsupp.plb文件被修改導致
通過md5碼對比,可以確定是有人對軟件的安裝介質進行了破壞,從而實現了惡意代碼的注入,從而實現了數據庫300天之后重啟之后無法正常啟動而是出現類似ORA-00600: internal error code, arguments: [16703], [1403], [20], [], [], [], [], [], [], [], [], []的錯誤.
溫馨提示
各位一定要從官方途徑下載oracle安裝介質,如果是從其他互聯網途徑下載一定要驗證md5,確保文件沒有被人惡意篡改,造成無可挽回的損壞.如果真的不幸遇到這類問題,請保護現場聯系我們
Tel:13429648788 Q Q:107644445 E-Mail:dba@xifenfei.com
我們可以通過使用bbed對tab$表數據數據進行恢復實現數據庫正常啟動,實現數據0丟失,最大限度搶救您的數據和減少業務恢復時間