通过oradebug和10046事件来分析数据库mount到open到底做了什么（通过oradebug和10046事件来分析数据库mount到open到底做了什么）

概述

闲来无事，整理了下数据库初始化过程的内容，这里主要通过oradebug和10046跟踪数据库mount到open的过程并获得一个跟踪文件，最后再对跟踪文件做个详细的分析，建议大家电脑上看，比较直观。

篇幅有限，后面再分享下怎么用gdb工具来分析。

---

1、使用 oradebug 跟踪 10046获得一个跟踪文件

shutdown immediate; startup mount; oradebug setmypid

//激活10046事件

oradebug event 10046 trace name context forever,level 12;

// 使用 oradebug tracefile_name 可以直接看到生成的 trace 文件的位置

oradebug tracefile_name; alter database open;

2、查看跟踪文件

$ vi /u01/app/oracle/diag/rdbms/nwppdb/nwppdb/trace/nwppdb_ora_3431.trc ===================== PARSING IN CURSOR #139897566702560 len=19 dep=0 uid=0 oct=35 lid=0 tim=1549191900462117 hv=1907384048 ad='c984af98' sqlid='a01hp0psv0rrh' alter database open END OF STMT PARSE #139897566702560:c=0,e=976,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1549191900462115 WAIT #139897566702560: nam='Disk file operations I/O' ela= 68 FileOperation=2 fileno=0 filetype=1 obj#=-1 tim=1549191900463257 WAIT #139897566702560: nam='control file sequential read' ela= 11 file#=0 block#=281 blocks=1 obj#=-1 tim=1549191901646978 WAIT #139897566702560: nam='instance state change' ela= 2110 layer=2 value=1 waited=1 obj#=-1 tim=1549191901649280 WAIT #139897566702560: nam='db file sequential read' ela= 69 file#=1 block#=520 blocks=1 obj#=-1 tim=1549191901650981 ===================== PARSING IN CURSOR #139897566694336 len=188 dep=1 uid=0 oct=1 lid=0 tim=1549191901653941 hv=4006182593 ad='c9807cf0' sqlid='32r4f1brckzq1' create table bootstrap$ ( END OF STMT PARSE #139897566694336:c=3000,e=2536,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901653939 EXEC #139897566694336:c=1000,e=683,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=0,tim=1549191901655013 CLOSE #139897566694336:c=0,e=9,dep=1,type=0,tim=1549191901655351 ===================== PARSING IN CURSOR #139897566694336 len=55 dep=1 uid=0 oct=3 lid=0 tim=1549191901657258 hv=2111436465 ad='c9806390' sqlid='6apq2rjyxmxpj' select line#, sql_text from bootstrap$ where obj# != :1 END OF STMT

从等待事件可以看到，db file单块读取了文件1的第520个数据块，这也正是引导块的定位过程。

3、第一个对象的创建

//跟踪文件显示： create table bootstrap$ ( line# number not null, obj# number not null, sql_text varchar2(4000) not null) storage (initial 50K objno 59 extents (file 1 block 520)) END OF STMT PARSE #139897566694336:c=3000,e=2536,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901653939 EXEC #139897566694336:c=1000,e=683,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=0,tim=1549191901655013 CLOSE #139897566694336:c=0,e=9,dep=1,type=0,tim=1549191901655351 ===================== PARSING IN CURSOR #139897566694336 len=55 dep=1 uid=0 oct=3 lid=0 tim=1549191901657258 hv=2111436465 ad='c9806390' sqlid='6apq2rjyxmxpj' select line#, sql_text from bootstrap$ where obj# != :1

注意：这一步骤实际上是oracle在内存中创建bootstrap$的结构，然后从数据文件中读取数据到内存中，完成第一次初始化。

在9i读取位置是文件1的377块，自动11g后变更为文件1的520块。

存储bootstrap$表定义的是在520号数据块，而bootstrap$表存储的内容是存储在521,522,523这几个数据块。从数据库的创建脚本$ORACLE_HOME/rdbms/admin/sql.bsq文件中，可以获得bootstrap$表的初始创建语句。

我们从数据库查一下，file 1 block 520上存储的是什么对象？

SQL> select segment_name,file_id,block_id from dba_extents where block_id=520 and file_id=1;

file 1 block 520存放的正是bootstrap$对象，查看trace 文件内容，下一步执行什么操作

select line#, SQL_text from bootstrap$ where obj# != :1

在创建并从数据文件中加载了bootstrap$的内容之后，oracle开始递归的从该表中读取信息，加载数据。那么bootstrap$中记录什么信息呢？

在数据库中，bootstrap$是一张实际存在的系统表。

SQL> desc bootstrap$;

4、分析跟踪文件

vi /u01/app/oracle/diag/rdbms/nwppdb/nwppdb/trace/nwppdb_ora_3431.trc

===================== PARSING IN CURSOR #139897566702560 len=19 dep=0 uid=0 oct=35 lid=0 tim=1549191900462117 hv=1907384048 ad='c984af98' sqlid='a01hp0psv0rrh' alter database open END OF STMT PARSE #139897566702560:c=0,e=976,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1549191900462115

# mount一开始，仍然是读取控制文件的内容

WAIT #139897566702560: nam='control file sequential read' ela= 32 file#=0 block#=1 blocks=1 obj#=-1 tim=1549191900463387 WAIT #139897566702560: nam='control file sequential read' ela= 6 file#=0 block#=15 blocks=1 obj#=-1 tim=1549191900463439 WAIT #139897566702560: nam='control file sequential read' ela= 5 file#=0 block#=17 blocks=1 obj#=-1 tim=1549191900463463

#开始从数据文件开始读取内容，等待事件为disk file operations i/o

WAIT #139897566702560: nam='Disk file operations I/O' ela= 68 FileOperation=2 fileno=0 filetype=1 obj#=-1 tim=1549191900463257 WAIT #139897566702560: nam='Disk file operations I/O' ela= 25 FileOperation=2 fileno=1 filetype=2 obj#=-1 tim=1549191900471288 WAIT #139897566702560: nam='Disk file operations I/O' ela= 8 FileOperation=2 fileno=2 filetype=2 obj#=-1 tim=1549191900471315 WAIT #139897566702560: nam='Disk file operations I/O' ela= 8 FileOperation=2 fileno=3 filetype=2 obj#=-1 tim=1549191900471335 WAIT #139897566702560: nam='Disk file operations I/O' ela= 7 FileOperation=2 fileno=4 filetype=2 obj#=-1 tim=1549191900471355 WAIT #139897566702560: nam='Disk file operations I/O' ela= 10 FileOperation=2 fileno=5 filetype=2 obj#=-1 tim=1549191900471386 WAIT #139897566702560: nam='Disk file operations I/O' ela= 12 FileOperation=2 fileno=201 filetype=2 obj#=-1 tim=1549191900471427

#读取数据文件，但注意，只是读取每个数据文件的第一个数据块,大家注意看block#=1及blocks=1

WAIT #139897566702560: nam='db file sequential read' ela= 7 file#=1 block#=1 blocks=1 obj#=-1 tim=1549191900471474 WAIT #139897566702560: nam='db file sequential read' ela= 5 file#=2 block#=1 blocks=1 obj#=-1 tim=1549191900471531 WAIT #139897566702560: nam='db file sequential read' ela= 4 file#=3 block#=1 blocks=1 obj#=-1 tim=1549191900471627 WAIT #139897566702560: nam='db file sequential read' ela= 3 file#=4 block#=1 blocks=1 obj#=-1 tim=1549191900471683 WAIT #139897566702560: nam='db file sequential read' ela= 3 file#=5 block#=1 blocks=1 obj#=-1 tim=1549191900471707

#接下来向控制文件写入内容

WAIT #139897566702560: nam='control file parallel write' ela= 400 files=1 block#=17 requests=1 obj#=-1 tim=1549191900472130 WAIT #139897566702560: nam='control file parallel write' ela= 325 files=1 block#=15 requests=1 obj#=-1 tim=1549191900472505 WAIT #139897566702560: nam='control file parallel write' ela= 387 files=1 block#=1 requests=1 obj#=-1 tim=1549191900472942 WAIT #139897566702560: nam='control file parallel write' ela= 428 files=1 block#=281 requests=1 obj#=-1 tim=1549191900473755 WAIT #139897566702560: nam='control file parallel write' ela= 378 files=1 block#=18 requests=1 obj#=-1 tim=1549191900474203 WAIT #139897566702560: nam='control file parallel write' ela= 526 files=1 block#=16 requests=1 obj#=-1 tim=1549191900474777 WAIT #139897566702560: nam='control file parallel write' ela= 769 files=1 block#=1 requests=1 obj#=-1 tim=1549191900475610

#和DBWR进程交互通讯，大家注意看from_process=10

WAIT #139897566702560: nam='rdbms ipc reply' ela= 587 from_process=10 timeout=2147483647 p3=0 obj#=-1 tim=1549191900476291

#接着又是读取控制文件

WAIT #139897566702560: nam='control file sequential read' ela= 5 file#=0 block#=1 blocks=1 obj#=-1 tim=1549191900476407 WAIT #139897566702560: nam='control file sequential read' ela= 3 file#=0 block#=16 blocks=1 obj#=-1 tim=1549191900476433 WAIT #139897566702560: nam='control file sequential read' ela= 3 file#=0 block#=18 blocks=1 obj#=-1 tim=1549191900476447 WAIT #139897566702560: nam='control file sequential read' ela= 3 file#=0 block#=321 blocks=1 obj#=-1 tim=1549191900476467

#与LGWR进程进行通讯

WAIT #139897566702560: nam='rdbms ipc reply' ela= 1158298 from_process=11 timeout=1800 p3=0 obj#=-1 tim=1549191901637697

#读取控制文件

WAIT #139897566702560: nam='control file sequential read' ela= 14 file#=0 block#=1 blocks=1 obj#=-1 tim=1549191901638548 WAIT #139897566702560: nam='control file sequential read' ela= 14 file#=0 block#=16 blocks=1 obj#=-1 tim=1549191901638767 WAIT #139897566702560: nam='control file sequential read' ela= 7 file#=0 block#=18 blocks=1 obj#=-1 tim=1549191901638841

#LOG FILE SYNC，也就是在MOUNT到OPEN会产生REDO

WAIT #139897566702560: nam='log file sync' ela= 5290 buffer#=6048 sync scn=995927 p3=0 obj#=-1 tim=1549191901645921

#读取控制文件

WAIT #139897566702560: nam='control file sequential read' ela= 28 file#=0 block#=1 blocks=1 obj#=-1 tim=1549191901646511 WAIT #139897566702560: nam='control file sequential read' ela= 13 file#=0 block#=16 blocks=1 obj#=-1 tim=1549191901646868

#一个新的等待事件，instance state change

WAIT #139897566702560: nam='instance state change' ela= 2110 layer=2 value=1 waited=1 obj#=-1 tim=1549191901649280

#这个点很重要，当读取数据文件，是读哪个数据文件呢，是1号文件，即SYSTEM数据文件，哪个数据块呢，是520号数据块，这个520数据块是什么含义呢？

WAIT #139897566702560: nam='db file sequential read' ela= 69 file#=1 block#=520 blocks=1 obj#=-1 tim=1549191901650981 ===================== PARSING IN CURSOR #139897566694336 len=188 dep=1 uid=0 oct=1 lid=0 tim=1549191901653941 hv=4006182593 ad='c9807cf0' sqlid='32r4f1brckzq1'

#这里马上就创建一个bootstrap$底层字典表，并且它是存储在file1 block 520,这样就结合起来了，也就是说上面520数据块是读取这个bootstap$的

create table bootstrap$ ( line# number not null, obj# number not null, sql_text varchar2(4000) not null) storage (initial 50K objno 59 extents (file 1 block 520)) END OF STMT PARSE #139897566694336:c=3000,e=2536,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901653939 EXEC #139897566694336:c=1000,e=683,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=0,tim=1549191901655013 CLOSE #139897566694336:c=0,e=9,dep=1,type=0,tim=1549191901655351 ===================== PARSING IN CURSOR #139897566694336 len=55 dep=1 uid=0 oct=3 lid=0 tim=1549191901657258 hv=2111436465 ad='c9806390' sqlid='6apq2rjyxmxpj'

#接下来ORACLE运行了一个SQL，这个SQL是从上面刚刚创建的bootstrap$表查询一条记录，那么它是查哪个对象？

select line#, sql_text from bootstrap$ where obj# != :1 END OF STMT PARSE #139897566694336:c=2000,e=1860,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901657256 BINDS #139897566694336: 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=7f3c70c48778 bln=22 avl=02 flg=05 value=59

#上面显示value=59,也就是59对象，即它要查不等于59号对象的所有存储在bootstrap$中的存储内容（大家注意：where obj#!=:1）

EXEC #139897566694336:c=1999,e=2776,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=867914364,tim=1549191901660493

#接着读取59号对象即bootstrap$表

WAIT #139897566694336: nam='db file sequential read' ela= 117 file#=1 block#=520 blocks=1 obj#=59 tim=1549191901661139

#这里是个多块读，开始从521数据块读，一直连续读3个块，把这几个数据块中存储的数据提取出来，可见多块读其实就是把存储在bootstrap$中的所有60个底层字典的数据全提取出来

WAIT #139897566694336: nam='db file scattered read' ela= 68 file#=1 block#=521 blocks=3 obj#=59 tim=1549191901661910

SQL> select obj# from bootstrap$ where DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID) in (521,522,523) order by 1; OBJ# ---------- -1 0 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 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 rows selected.

#这里就是提取内容了，省略一部分

FETCH #139897566694336:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=1,dep=1,og=4,plh=867914364,tim=1549191901662462 FETCH #139897566694336:c=0,e=32,p=0,cr=1,cu=0,mis=0,r=1,dep=1,og=4,plh=867914364,tim=1549191901663730 FETCH #139897566694336:c=1000,e=105,p=0,cr=1,cu=0,mis=0,r=1,dep=1,og=4,plh=867914364,tim=1549191901664598 STAT #139897566694336 id=1 cnt=59 pid=0 pos=1 obj=59 op='TABLE ACCESS FULL BOOTSTRAP$ (cr=61 pr=4 pw=0 time=1363 us)' CLOSE #139897566694336:c=0,e=24,dep=1,type=0,tim=1549191901676598

#根据上述提取出来的内容，创建0号对象SYSTEM ROLLBACK SEGMENT,且指定对象号objno 0,以及指定存储在哪个文件及哪个数据块file 1 block 128

===================== PARSING IN CURSOR #139897566696448 len=129 dep=1 uid=0 oct=36 lid=0 tim=1549191901678179 hv=1119914026 ad='7f3c70b7dcb0' sqlid='864bmh11c121a' CREATE ROLLBACK SEGMENT SYSTEM STORAGE ( INITIAL 112K NEXT 56K MINEXTENTS 1 MAXEXTENTS 32765 OBJNO 0 EXTENTS (FILE 1 BLOCK 128)) END OF STMT PARSE #139897566696448:c=1000,e=1382,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901678177 EXEC #139897566696448:c=0,e=204,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=0,tim=1549191901678842 CLOSE #139897566696448:c=0,e=9,dep=1,type=0,tim=1549191901679128

#创建2号对象c_obj# cluster table

===================== PARSING IN CURSOR #139897566696448 len=209 dep=1 uid=0 oct=4 lid=0 tim=1549191901680179 hv=1323908363 ad='7f3c70b950f8' sqlid='7j058yj7fkg8b' CREATE CLUSTER C_OBJ#("OBJ#" NUMBER) PCTFREE 5 PCTUSED 40 INITRANS 2 MAXTRANS 255 STORAGE ( INITIAL 136K NEXT 200K MINEXTENTS 1 MAXEXTENTS 2147483645 PCTINCREASE 0 OBJNO 2 EXTENTS (FILE 1 BLOCK 144)) SIZE 800 END OF STMT PARSE #139897566696448:c=1000,e=956,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901680177 EXEC #139897566696448:c=0,e=253,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=0,tim=1549191901680705 CLOSE #139897566696448:c=0,e=7,dep=1,type=0,tim=1549191901680831

#创建3号对象I_OBJ# 基于C_OBJ#的INDEX

===================== PARSING IN CURSOR #139897566661424 len=191 dep=1 uid=0 oct=9 lid=0 tim=1549191901683676 hv=2739073813 ad='c98022f8' sqlid='0cmnx32jn5wsp' CREATE INDEX I_OBJ# ON CLUSTER C_OBJ# PCTFREE 10 INITRANS 2 MAXTRANS 255 STORAGE ( INITIAL 64K NEXT 1024K MINEXTENTS 1 MAXEXTENTS 2147483645 PCTINCREASE 0 OBJNO 3 EXTENTS (FILE 1 BLOCK 168)) END OF STMT PARSE #139897566661424:c=2000,e=2812,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=1876228229,tim=1549191901683673 EXEC #139897566661424:c=0,e=541,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=1876228229,tim=1549191901684588 STAT #139897566661424 id=1 cnt=0 pid=0 pos=1 obj=0 op='INDEX BUILD UNIQUE I_OBJ# (cr=0 pr=0 pw=0 time=8 us)' STAT #139897566661424 id=2 cnt=0 pid=1 pos=1 obj=0 op='SORT CREATE INDEX (cr=0 pr=0 pw=0 time=0 us cost=0 size=0 card=0)' STAT #139897566661424 id=3 cnt=0 pid=2 pos=1 obj=2 op='TABLE ACCESS FULL C_OBJ# (cr=0 pr=0 pw=0 time=0 us)' CLOSE #139897566661424:c=0,e=7,dep=1,type=0,tim=1549191901685131

#创建4号对象TAB$

===================== PARSING IN CURSOR #139897566661424 len=827 dep=1 uid=0 oct=1 lid=0 tim=1549191901688132 hv=4071397944 ad='c98009d8' sqlid='gsc5dr3tat6js' CREATE TABLE TAB$("OBJ#" END OF STMT PARSE #139897566661424:c=3999,e=2915,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901688130 EXEC #139897566661424:c=0,e=488,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=0,tim=1549191901688954 CLOSE #139897566661424:c=0,e=8,dep=1,type=0,tim=1549191901689267 。。。。。

#开始在已经创建好的60个底层字典表中查询某些信息

===================== PARSING IN CURSOR #139897566661424 len=106 dep=1 uid=0 oct=3 lid=0 tim=1549191901853096 hv=3628073639 ad='c97b5788' sqlid='bqbdby3c400p7' select rowcnt,blkcnt,empcnt,avgspc,chncnt,avgrln,nvl(degree,1), nvl(instances,1) from tab$ where obj# = :1 END OF STMT PARSE #139897566661424:c=1000,e=824,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901853095 ===================== PARSING IN CURSOR #139897566660480 len=136 dep=1 uid=0 oct=3 lid=0 tim=1549191901853898 hv=2541974715 ad='c97b4c88' sqlid='f8mu51fbs6x5v' 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 #139897566660480:c=1000,e=635,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901853897 ===================== PARSING IN CURSOR #139897566696448 len=70 dep=1 uid=0 oct=3 lid=0 tim=1549191901854777 hv=3377894161 ad='c97b41d8' sqlid='32d4jrb4pd4sj' select charsetid, charsetform from col$ where obj# = :1 and col# = :2 END OF STMT PARSE #139897566696448:c=1000,e=681,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1549191901854776

---

总结

1、oracle mount到open,先读取控制文件，然后读取每个数据文件，接着读取第1号数据文件SYSTEM的第520数据块，然后在这个数据块创建字典表bootstrap$

2、接着从创建好的bootstrap$把存储在其中的59个对象（包括表，索引，CLUSTER TABLE）全部提取出来，依次创建这59个对象

3、为何是59个对象，因为过滤了bootstrap$表本身

4、依次创建是何义呢，即指定这些59个对象是在哪个文件，哪个数据块，也就是说这些数据块必须要固定在一个固定的位置，不能随便变换了，这里是ORACLE核心代码固定死了

还有一个依次的意思，就是以这59个对象obj#的编号大小，依次创建这些对象

5、创建完这些59个对象后，然后使用这些创建好的对象，查询一些对于数据库OPEN有关的信息

6、bootstrap$表的定义本身就是存储在1号数据文件的520号数据块

bootstrap$实际上是记录了一些数据库系统基本对象的创建语句。oracle通过bootstrap$进行引导，进一步创建相关的重要对象，从而启动了数据库。

存储这些60个对象的不管是表或是索引或CLUSTER TABLE，它们里面存储的数据，而非DDL，是永远存在在1号数据文件对应的哪些数据块上的，不会每次都去重新插入的。

可以判断这60个对象的数据是在创建数据库时就已经初始化好了。

另外，521，522，523这3个数据块是存储了60个对象的数据，如果这3个数据块坏了，数据库肯定启动不了。

7、ORACLE在创建这59个底层对象所采用CREATE TABLE语法，仅适用于这些对象，不适用于普通的表对象

8、还有一点，存储bootstrap$表定义的是在520号数据块，而bootstrap$表存储的内容是存储在521,522,523这几个数据块，可见ORACLE设计的精妙之处。

后面会分享更多关于DBA方面的实验内容，感兴趣的朋友可以关注下！！大家最好自己测试下，印象会比较深刻，也更容易去理解。

,