Skip to content

数据读取之逻辑读简单解析–BUFFER CACHE 关于 consistent read–一致性读–Logical read-逻辑读-current read当前读–物理读,详见:http://blog.csdn.net/haibusuanyun/article/details/11489091
一、实验数据准备–查出一条数据的ROWID,及FILE_ID,BLOCK_ID等信息
BYS@ bys3>select rowid,test.* from test where rownum=1;
ROWID OBJECT_NAME OBJECT_ID STATUS
—————— ———— ———- ——-
AAAFSJAAEAAAACrAAA UNDO$ 15 VALID
使用下面语句查出相应行的FILE_ID,BLOCK_ID,关于ROWID,详见:http://blog.csdn.net/q947817003/article/details/11490051
col object_name for a12
col colname for a10
select a.rowid,a.object_id,a.file_id,a.block_id,a.row_num,b.object_name,a.colname from
(select rowid,
dbms_rowid.rowid_object(rowid) object_id,
dbms_rowid.rowid_relative_fno(rowid) file_id,
dbms_rowid.rowid_block_number(rowid) block_id,
dbms_rowid.rowid_row_number(rowid) row_num,
&colname as colname from &tablename t) a,
dba_objects b
where a.object_id=b.object_id;
运行上述语句,按提示输入:&colname 列名 ;&tablename 表名即可显示类似以下信息: 我这里是输入 test 表的object_name列
ROWID OBJECT_ID FILE_ID BLOCK_ID ROW_NUM OBJECT_NAME COLNAME
—————— ———- ———- ———- ———- ———— ———-
AAAFSJAAEAAAACrAAD 21641 4 171 3 TEST I_USER1
AAAFSJAAEAAAACrAAC 21641 4 171 2 TEST CON$
AAAFSJAAEAAAACrAAB 21641 4 171 1 TEST ICOL$
AAAFSJAAEAAAACrAAA 21641 4 171 0 TEST UNDO$
#############################
二、关于BH buffer header,buckets,block_buffers介绍:
详见: buffer cache实验1-内存结构图解

#############################

三.结合图1,解析发出查询语句,ORACLE如何读数据?
select a from b where rownum=1;语句发出后, —只涉及buffer cache中的读取,语句的解析暂不考虑,以后补充吧。
–>>首先查出第一行数据的ROWID–使用有dbms_rowid.ROWID_BLOCK_NUMBER(rowid),
–>>根据ROWID得出DBA
–>>到SGA中BUFFER CACHE查找此数据。
–>>首先把DBA信息使用内部HASH函数进行运算
–>>根据生成值找到相应HASH BUCKET(包含首、尾BH地址) –共享池
–>>通过HASH BACKET找到cache buffers chains- -此步需要先要获取latch:cache buffers chains
–>>在cache buffers chains上顺序查询到所需BH buffer header –通过内部表x$bh,在BH中找到BA信息 buffer address
–>>根据BH中的BA信息,就找到了BUFFER CACHE中存放所要查询数据块具体数据的内存块— 此步需要先获取Buffer pin S (0–>1)–在BH上加此锁
–>>返回数据至相应的查询进程; 一次逻辑读的读取操作到此完成。 此后还需要释放在BH上的Buffer pin S 锁
–>> 此时需要先获取latch:cache buffers chains,
–>>在上一步获取的 latch:cache buffers chains保护下,将BH上的 BH上的Buffer pin S 锁释放(1–>0)
–>>释放 latch:cache buffers chains,至此一次逻辑读的操作才全部完成。。

四、总结:一次逻辑读时CBC latch锁及Buffer pin锁的获取和释放过程如下:
1.加Latch X
2.进入hash chain,在相应的BH上加Buffer pin S (0–>1)
3.释放Latch X
4.进行逻辑读–也就是通过BH中的buffer adderss找到数据块在内存中真实位置 —假如读了1MS
5.加Latch X
6.释放Buffer pin S (1–>0) 0:没锁 1:共享锁 2:独占锁
7.释放Latch X

数据读取之逻辑读简单解析–关于BUFFER CACHE

—友情提示,内容较多,可以从博文左上的+目录选择小节方便阅读。
实验思路: –实验相关TRACE文件:http://download.csdn.net/detail/q947817003/6646723
1.数据库OPEN,,做DML操作不提交,查看检查点。
2.SHUTDOWN ABORT并重启到MOUNT并查询检查点
3.DUMP控制文件查看CHECKPOINT_CHANGE#/RBA
4.DUMP数据文件查看CHECKPOINT_CHANGE#/RBA,与DUMP控制文件对比
5.DUMP REDO日志文件,查看、对比CHECKPOINT_CHANGE#/RBA
6.使用BBED查看数据文件头中的CHECKPOINT_CHANGE#/RBA
7.执行EVENT事件的语句,OPEN数据库,再DUMP控制文件
8.分析OPEN时,通过ALERT日志查看的恢复过程–前滚
9.分析OPEN时,EVENT事件生成的TRACE中查看恢复过程–前滚
10.OPEN数据库时,通过ALERT日志及EVENT事件生成的TRACE中信息解析实例恢复的回滚
11.分析OPEN后的控制文件信息

参考资料及感谢:
guoyJoe http://blog.csdn.net/guoyJoe/article/details/9034425
dbsnake http://www.dbsnake.com/oracle-instance-recovery-end-point.html

实验结论有:
1.控制文件提供恢复所需当前REDO日志的RBA信息,当前REDO日志提供具体的用于恢复的日志内容,最终是将日志内容应用于数据文件。–实例恢复三者不能缺。
2.数据库OPEN时开始实例恢复,先应用日志内容,应用完后从alert日志中来看是已经可以连接至数据库,此时如果UNDO未完成,就有用户发出操作,数据库进程会将回滚后的数据发送至用户- -可能会有等待。
3.重要的一点,数据文件、当前REDO日志文件、控制文件正常时实例恢复无需DBA干预,自动完成哈哈。
4.如果当前REDO日志丢了,只能做不完全恢复了。

关于实例恢复起止点:–来自dbsnake
可能会出现On Disk RBA比Low Cache RBA小的情况,如果Oracle发现存在这种情况,则会强制写redo。
On Disk RBA只是表示Instance Recovery的时候至少要恢复到On Disk RBA,它只是真正的current redo log file的最尾端一个前镜像。
实例恢复的起点是:Low Cache RBA和Thread Checkpoint RBA中的较大值; 实例恢复的终点就是current redo log file的最尾端。 On-Disk RBA是要最低恢复到的位置–事实上是只要On-Disk RBA后还有日志块就要恢复完的。
Oracle在做实例恢复的时候是受隐含参数_two_pass的控制,其默认为true,这表示要Oracle做实例恢复的时候是采用Two Pass Recovery,即要扫描current redo log file两次。
Two Pass Recovery的核心是在做实例恢复时要去掉那些已经被写入数据文件的数据块所对应的redo record,Oracle称这些redo record为Block Written Record (BWR)。
###################################################################
1.数据库正常运行,多种途径查看数据库中检查点
在普通用户下执行DML操作不提交
BYS@ bys3>set time on
13:18:17 BYS@ bys3>select * from a; –此表在USER表空间。
B
———-
55
8
0
3
13:18:21 BYS@ bys3>delete a;
4 rows deleted.
13:18:36 BYS@ bys3>select * from a;
no rows selected
再打开一个会话(同一会话切换用户会提交操作),多种途径查看数据库中检查点:详见:http://blog.csdn.net/q947817003/article/details/11590735
SYS@ bys3>set time on
13:18:44 SYS@ bys3>col name for a35
13:18:52 SYS@ bys3>select dbid,name,checkpoint_change# from v$database;
DBID NAME CHECKPOINT_CHANGE#
———- ———————————– ——————
3358363031 BYS3 1991217
13:18:59 SYS@ bys3>select file#,name,checkpoint_change#,to_char(checkpoint_time,’yyyy-mm-dd hh24:mi:ss’) cptime from v$datafile;
FILE# NAME CHECKPOINT_CHANGE# CPTIME
———- ———————————– —————— ——————-
1 /u01/oradata/bys3/system01.dbf 1991217 2013-12-02 13:17:26
2 /u01/oradata/bys3/sysaux01.dbf 1991217 2013-12-02 13:17:26
3 /u01/oradata/bys3/undotbs01.dbf 1991217 2013-12-02 13:17:26
4 /u01/oradata/bys3/user01.dbf 1991217 2013-12-02 13:17:26
13:19:25 SYS@ bys3>select name,checkpoint_change# from v$datafile_header;
NAME CHECKPOINT_CHANGE#
———————————– ——————
/u01/oradata/bys3/system01.dbf 1991217
/u01/oradata/bys3/sysaux01.dbf 1991217
/u01/oradata/bys3/undotbs01.dbf 1991217
/u01/oradata/bys3/user01.dbf 1991217
当前当前REDO日志使用情况:
13:19:57 SYS@ bys3>col member for a30
13:20:01 SYS@ bys3>select a.member,a.type,b.thread#,b.sequence#,b.bytes/1024/1024 MB,b.status,b.archived from v$logfile a,v$log b where a.group#=b.group#;
MEMBER TYPE THREAD# SEQUENCE# MB STATUS ARC
—————————— ——- ———- ———- ———- —————- —
/u01/oradata/bys3/redo01.log ONLINE 1 106 50 INACTIVE YES
/u01/oradata/bys3/redo02.log ONLINE 1 107 50 CURRENT NO
/u01/oradata/bys3/redo03.log ONLINE 1 105 50 INACTIVE YES
###################################################################

2.模拟断电–shutdown abort,并重启到MOUNT 查询检查点
13:20:02 SYS@ bys3>shutdown abort; —-13:22:11执行完此命令
ORACLE instance shut down.
13:22:11 SYS@ bys3>
alert日志: –推荐个小方法:把alert日志做一个软链接到ORACLE用户家目录,查看方便。
[oracle@bys3 ~]$ cat alert_bys3.log
Mon Dec 02 13:22:09 2013
Shutting down instance (abort)
License high water mark = 4
USER (ospid: 846): terminating the instance
Instance terminated by USER, pid = 846
Mon Dec 02 13:22:11 2013
Instance shutdown complete
######################################
重启数据库到MOUNT,从数据库中查看数据库中检查点、控制文件及数据文件头检查点,一致则无需介质恢复
数据库MOUNT状态下直接在数据库中使用SQL语句查询:
SYS@ bys3>select status from v$instance;
STATUS
————
MOUNTED
SYS@ bys3>select dbid,name,checkpoint_change# from v$database; –数据库全局-检查点 SCN,在控制文件中
DBID NAME CHECKPOINT_CHANGE#
———- ——— ——————
3358363031 BYS3 1991217
SYS@ bys3>select file#,name,checkpoint_change#,to_char(checkpoint_time,’yyyy-mm-dd hh24:mi:ss’) cptime from v$datafile; –checkpoint scn,表示该数据文件最近一次执行检查点操作时的SCN,在控制文件中。
FILE# NAME CHECKPOINT_CHANGE# CPTIME
———- ———————————– —————— ——————-
1 /u01/oradata/bys3/system01.dbf 1991217 2013-12-02 13:17:26
2 /u01/oradata/bys3/sysaux01.dbf 1991217 2013-12-02 13:17:26
3 /u01/oradata/bys3/undotbs01.dbf 1991217 2013-12-02 13:17:26
4 /u01/oradata/bys3/user01.dbf 1991217 2013-12-02 13:17:26
SYS@ bys3>select name,checkpoint_change# from v$datafile_header; –CHECKPOINT_CHANGE#表示该数据文件最近一次执行检查点操作时的SCN,在数据文件头
NAME CHECKPOINT_CHANGE#
———————————– ——————
/u01/oradata/bys3/system01.dbf 1991217
/u01/oradata/bys3/sysaux01.dbf 1991217
/u01/oradata/bys3/undotbs01.dbf 1991217
/u01/oradata/bys3/user01.dbf 1991217
###################################################################
3.DUMP控制文件查看CHECKPOINT_CHANGE#/RBA
更详细DUMP控制文件方式见:http://blog.csdn.net/q947817003/article/details/16370273
SYS@ bys3>alter session set events ‘immediate trace name controlf level 12’;
Session altered.
SYS@ bys3>select value from v$diag_info where name like ‘Default%’;
VALUE
——————————————————————————
/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_980.trc
查看TRACE文件: –截取部分内容
***************************************************************************
DATABASE ENTRY
***************************************************************************
(size = 316, compat size = 316, section max = 1, section in-use = 1,
last-recid= 0, old-recno = 0, last-recno = 0)
(extent = 1, blkno = 1, numrecs = 1)
11/14/2013 14:23:19
DB Name “BYS3”
Database flags = 0x00404001 0x00001200
Controlfile Creation Timestamp 11/14/2013 14:23:21
Incmplt recovery scn: 0x0000.00000000
Resetlogs scn: 0x0000.00000001 Resetlogs Timestamp 11/14/2013 14:23:19
Prior resetlogs scn: 0x0000.00000000 Prior resetlogs Timestamp 01/01/1988 00:00:00
Redo Version: compatible=0xb200000
#Data files = 4, #Online files = 4
Database checkpoint: Thread=1 scn: 0x0000.001e6231
Threads: #Enabled=1, #Open=1, Head=1, Tail=1
enabled threads: 01000000 00000000 00000000 00000000 00000000 00000000
Max log members = 5, Max data members = 1
Arch list: Head=2, Tail=2, Force scn: 0x0000.001b6c94scn: 0x0000.00000000
Activation ID: 3358374039
SCN compatibility 1
Auto-rollover enabled
Controlfile Checkpointed at scn: 0x0000.001e6286 12/02/2013 13:17:28 —这是增量检查点的位置SCN -1991302
thread:0 rba:(0x0.0.0)
###############
可以看到检查点的信息:Database checkpoint: Thread=1 scn: 0x0000.001e6231
换算为十进制的SCN为: —与上一步查询对应
SYS@ bys3>select to_number(‘1e6231′,’xxxxxxxxx’) from dual;
TO_NUMBER(‘1C8E12′,’XXXXXXXXX’)
——————————-
1991217
###############
***************************************************************************
CHECKPOINT PROGRESS RECORDS
***************************************************************************
(size = 8180, compat size = 8180, section max = 4, section in-use = 0,
last-recid= 0, old-recno = 0, last-recno = 0)
(extent = 1, blkno = 2, numrecs = 4)
THREAD #1 – status:0x2 flags:0x0 dirty:104 —脏块数量104
low cache rba:(0x6b.3.0) on disk rba:(0x6b.197.0) —数据文件检查点 Scn以及stop scn值据说来自于当前REDO日志
on disk scn: 0x0000.001e638d 12/02/2013 13:21:37 –ON DISK SCN
resetlogs scn: 0x0000.00000001 11/14/2013 14:23:19
heartbeat: 833133356 mount id: 3360007946
################
在检查点进程记录部分,记录了Dirty Buffer的数量是104.
包含Low Cache RBA和On Disk RBA的信息,
low cache rba:(0x6b.3.0) on disk rba:(0x6b.197.0)
— low cache rba:(0x6b.3.0): 实例恢复的起点:107号日志,第3个块,第0个字节
–on disk rba:(0x6b.197.0): 实例恢复的终点:107号日志,第407个块,第0个字节 –最前面结论是实例恢复终点实际为current redo log file的最尾端,但是在控制文件、日志中记录的是这个 on disk rba

on disk scn: 0x0000.001e638d 12/02/2013 13:21:37
数据库恢复的检查点终点是SCN–0x0000.001e638d,十进制是:1991565。
On-Disk RBA的SCN是1991565,这是实例恢复的终点。
数据库的恢复SCN范围也就由此确定,即SCN范围:增量检查点:1991302–On-Disk RBA,用SCN表示即:1991302 ===>>>1991565

***************************************************************************
DATA FILE RECORDS
***************************************************************************
(size = 520, compat size = 520, section max = 100, section in-use = 4,
last-recid= 7, old-recno = 0, last-recno = 0)
(extent = 1, blkno = 7, numrecs = 100)
DATA FILE #1: DATA FILE #2: DATA FILE #3: 和DATA FILE #3差不多,并且在本实验中不涉及,精简篇幅就省略了。
DATA FILE #4:
name #8: /u01/oradata/bys3/user01.dbf
creation size=6400 block size=8192 status=0xe head=8 tail=8 dup=1
tablespace 4, index=5 krfil=4 prev_file=0
unrecoverable scn: 0x0000.00000000 01/01/1988 00:00:00
Checkpoint cnt:167 scn: 0x0000.001e6231 12/02/2013 13:17:26 —cnt:167是检查点计数,来自数据文件。–与下一步DUMP数据文件中SYSTEM表空间数据文件的CTL CNT对应。一致说明来自同一版本,而不是备份。
Stop scn: 0xffff.ffffffff 12/02/2013 13:16:13 –STOP SCN是FFFF,数据文件的STOP SCP不等于Checkpoint SCN。意味着数据库上一次关闭未执行完全检查点,是异常关闭。故需要实例恢复。
Creation Checkpointed at scn: 0x0000.000034f9 11/14/2013 14:26:26
thread:1 rba:(0x1.ce8a.10)
enabled threads: 01000000 00000000 00000000 00000000 00000000 00000000
Offline scn: 0x0000.00000000 prev_range: 0
Online Checkpointed at scn: 0x0000.00000000
thread:0 rba:(0x0.0.0)
enabled threads: 00000000 00000000 00000000 00000000 00000000 00000000
Hot Backup end marker scn: 0x0000.00000000
aux_file is NOT DEFINED
Plugged readony: NO
Plugin scnscn: 0x0000.00000000
Plugin resetlogs scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
Foreign creation scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
Foreign checkpoint scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
Online move state: 0
########################
这里在第1步做DML操作时,所在的是USER表空间。
DATA FILE #4: 中的检查点信息如下:
Checkpoint cnt:167 scn: 0x0000.001e6231 12/02/2013 13:17:26
–控制文件中保存的数据文件检查点SCN=1e6231 转成10进制为1991217,与前文吻合
Stop scn: 0xffff.ffffffff 12/11/2012 22:53:05
–结束的SCN填无穷大,说明是异常关机的,重启数据库必须做实例恢复
###################################################################
4.DUMP数据文件查看CHECKPOINT_CHANGE#/RBA,与DUMP控制文件对比
更详细DUMP数据文件方式见:http://blog.csdn.net/q947817003/article/details/16369041
SYS@ bys3>alter system set events ‘immediate trace name file_hdrs level 3’; –最好和上一步DUMP控制文件在不同的会话
System altered.
SYS@ bys3>select value from v$diag_info where name like ‘Default%’;
VALUE
———————————————————————-
/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_1010.trc
查看TRACE文件: –截取部分内容–

DATA FILE #1:
name #4: /u01/oradata/bys3/system01.dbf
creation size=64000 block size=8192 status=0xe head=4 tail=4 dup=1
tablespace 0, index=1 krfil=1 prev_file=0
unrecoverable scn: 0x0000.00000000 01/01/1988 00:00:00
Checkpoint cnt:167 scn: 0x0000.001e6231 12/02/2013 13:17:26 ———–CKPT CNT 167与上一步DUMP控制文件中对应
Stop scn: 0xffff.ffffffff 12/02/2013 13:16:13 ——- –STOP SCN是FFFF,数据文件的STOP SCP不等于Checkpoint SCN。意味着数据库上一次关闭未执行完全检查点,是异常关闭。故需要实例恢复。
Creation Checkpointed at scn: 0x0000.00000015 11/14/2013 14:24:22
thread:1 rba:(0x1.3.10)
enabled threads: 01000000 00000000 00000000 00000000 00000000 00000000
Offline scn: 0x0000.00000000 prev_range: 0
Online Checkpointed at scn: 0x0000.00000000
thread:0 rba:(0x0.0.0)
enabled threads: 00000000 00000000 00000000 00000000 00000000 00000000
000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000
Hot Backup end marker scn: 0x0000.00000000
aux_file is NOT DEFINED
Plugged readony: NO
Plugin scnscn: 0x0000.00000000
Plugin resetlogs scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
Foreign creation scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
Foreign checkpoint scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
Online move state: 0
V10 STYLE FILE HEADER:
Compatibility Vsn = 186646528=0xb200000
Db ID=3358363031=0xc82c8d97, Db Name=’BYS3′
Activation ID=0=0x0
Control Seq=8489=0x2129, File size=64000=0xfa00
File Number=1, Blksiz=8192, File Type=3 DATA
Tablespace #0 – SYSTEM rel_fn:1
Creation at scn: 0x0000.00000015 11/14/2013 14:24:22
Backup taken at scn: 0x0000.00000000 01/01/1988 00:00:00 thread:0
reset logs count:0x318f5cd7 scn: 0x0000.00000001
prev reset logs count:0x0 scn: 0x0000.00000000
recovered at 12/02/2013 13:17:26
status:0x2004 root dba:0x00400208 chkpt cnt: 167 ctl cnt:166 ———–CKPT CNT 167, CTL CNT 166与上一步DUMP控制文件中对应
###################################################
Tablespace #4 – USERS rel_fn:4
Creation at scn: 0x0000.000034f9 11/14/2013 14:26:26
Backup taken at scn: 0x0000.00000000 01/01/1988 00:00:00 thread:0
reset logs count:0x318f5cd7 scn: 0x0000.00000001
prev reset logs count:0x0 scn: 0x0000.00000000
recovered at 12/02/2013 13:17:26
status:0x4 root dba:0x00000000 chkpt cnt: 168 ctl cnt:167
begin-hot-backup file size: 0
Checkpointed at scn: 0x0000.001e6231 12/02/2013 13:17:26 ——-检查点 scn: 0x0000.001e6231与前文吻合
thread:1 rba:(0x6b.2.10) ——–REDO日志的地址0x6b.2.10–-> 107号日志,第2号块,第16个字节
enabled threads: 01000000 00000000 00000000 00000000 00000000 00000000
Backup Checkpointed at scn: 0x0000.00000000
thread:0 rba:(0x0.0.0)
enabled threads: 00000000 00000000 00000000 00000000 00000000 00000000
External cache id: 0x0 0x0 0x0 0x0
Absolute fuzzy scn: 0x0000.00000000
Recovery fuzzy scn: 0x0000.00000000 01/01/1988 00:00:00
Terminal Recovery Stamp 01/01/1988 00:00:00
Platform Information: Creation Platform ID: 10
Current Platform ID: 10 Last Platform ID: 10
DUMP OF TEMP FILES: 1 files in database

第3步中:《《注意:
从控制文件中得到重做日志恢复起始地址如下:
low cache rba:(0x6b.3.0) on disk rba:(0x6b.197.0)
— low cache rba:(0x6b.3.0):
实例恢复的起点:107号日志,第3个块,第0个字节
–on disk rba:(0x6b.197.0):
实例恢复的终点:107号日志,第407个块,第0个字节 –具体是不是终点,最后讨论

on disk scn: 0x0000.001e638d 12/02/2013 13:21:37
数据库恢复的检查点终点是SCN–0x0000.001e638d,十进制是:1991565。
On-Disk RBA的SCN是1991565,这是实例恢复的终点。
数据库的恢复SCN范围也就由此确定,即SCN范围:最后检查点:1991217–On-Disk RBA,用SCN表示即:1991217 ===>>>1991565》》
–说明:
实例恢复的起点是Low Cache RBA和Thread Checkpoint RBA中的最大值, 实例恢复的终点就是current redo log file的最尾端而不是On-Disk RBA。 On-Disk RBA是要最低恢复到的位置。
这样,本实验中实例恢复的起始的重做日志是以控制文件中的low cache rba:(0x6b.3.0)开始恢复,而不是从文件头的thread:1 rba:(0x6b.2.10)
########################################################################
5.DUMP REDO日志文件 –在第一步已经确定了当前日志是redo02.log
更详细方法,见:http://blog.csdn.net/q947817003/article/details/16370203
SYS@ bys3>alter system dump logfile ‘/u01/oradata/bys3/redo02.log’;
System altered.
SYS@ bys3>select value from v$diag_info where name like ‘Default%’;
VALUE
——————————————————————
/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_1906.trc
REDO日志DUMP最后一个REDO RECORD 的一部分CHANGE #1: –不知道如何解读,留白吧???
REDO RECORD – Thread:1 RBA: 0x00006b.00000194.0084 LEN: 0x0418 VLD: 0x09 —与上一步的对应
SCN: 0x0000.001e638c SUBSCN: 1 12/02/2013 13:21:37
CHANGE #1 TYP:2 CLS:1 AFN:1 DBA:0x004007e1 OBJ:288 SCN:0x0000.001e6386 SEQ:2 OP:11.5 ENC:0 RBL:0
KTB Redo
op: 0x11 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F xid: 0x0009.017.00000642 uba: 0x00c00cac.00f9.28
Block cleanout record, scn: 0x0000.001e638b ver: 0x01 opt: 0x02, entries follow…
itli: 2 flg: 2 scn: 0x0000.001e6386
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x004007e1 hdba: 0x004007e0
itli: 1 ispac: 0 maxfr: 4863
tabn: 0 slot: 1(0x1) flag: 0x2c lock: 1 ckix: 182
ncol: 19 nnew: 6 size: -7
col 4: [ 7] 78 71 0c 02 0e 16 26
col 5: *NULL*
col 6: [ 7] 78 71 0c 02 0e 17 26
col 7: [21]
c0 06 60 3d 13 34 56 13 34 56 13 34 56 13 34 56 13 34 56 1e 0b
col 9: [ 1] 80
col 10: [ 1] 80
###################################################################
6:使用BBED查看数据文件头CHECKPOINT_CHANGE#及rba
[oracle@bys3 ~]$ cat par.bbd
blocksize=8192
listfile=bbedfile.txt
mode=edit
[oracle@bys3 ~]$ cat bbedfile.txt
1 /u01/oradata/bys3/system01.dbf 524288000
2 /u01/oradata/bys3/sysaux01.dbf 340787200
3 /u01/oradata/bys3/undotbs01.dbf 209715200
4 /u01/oradata/bys3/user01.dbf 52428800
[oracle@bys3 ~]$ bbed parfile=par.bbd
Password:
BBED: Release 2.0.0.0.0 – Limited Production on Sun Dec 1 22:29:18 2013
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
************ !!! For Oracle Internal Use only !!! ***************
BBED> set file 4 block 1
FILE# 4
BLOCK# 1
BBED> map /v
File: /u01/oradata/bys3/user01.dbf (4)
Block: 1 Dba:0x01000001
————————————————————
Data File Header
struct kcvfh, 860 bytes @0
struct kcvfhbfh, 20 bytes @0
struct kcvfhhdr, 76 bytes @20
ub4 kcvfhrdb @96
struct kcvfhcrs, 8 bytes @100
ub4 kcvfhcrt @108
ub4 kcvfhrlc @112
struct kcvfhrls, 8 bytes @116
ub4 kcvfhbti @124
struct kcvfhbsc, 8 bytes @128
ub2 kcvfhbth @136
ub2 kcvfhsta @138
struct kcvfhckp, 36 bytes @484
ub4 kcvfhcpc @140
ub4 kcvfhrts @144
ub4 kcvfhccc @148
struct kcvfhbcp, 36 bytes @152
ub4 kcvfhbhz @312
struct kcvfhxcd, 16 bytes @316
sword kcvfhtsn @332
ub2 kcvfhtln @336
text kcvfhtnm[30] @338
ub4 kcvfhrfn @368
struct kcvfhrfs, 8 bytes @372
ub4 kcvfhrft @380
struct kcvfhafs, 8 bytes @384
ub4 kcvfhbbc @392
ub4 kcvfhncb @396
ub4 kcvfhmcb @400
ub4 kcvfhlcb @404
ub4 kcvfhbcs @408
ub2 kcvfhofb @412
ub2 kcvfhnfb @414
ub4 kcvfhprc @416
struct kcvfhprs, 8 bytes @420
struct kcvfhprfs, 8 bytes @428
ub4 kcvfhtrt @444
ub4 tailchk @8188

BBED> print kcvfhckp
struct kcvfhckp, 36 bytes @484
struct kcvcpscn, 8 bytes @484
ub4 kscnbas @484 0x001e6231
ub2 kscnwrp @488 0x0000
ub4 kcvcptim @492 0x31a859e6
ub2 kcvcpthr @496 0x0001
union u, 12 bytes @500
struct kcvcprba, 12 bytes @500
ub4 kcrbaseq @500 0x0000006b
ub4 kcrbabno @504 0x00000002
ub2 kcrbabof @508 0x0010
ub1 kcvcpetb[0] @512 0x02
ub1 kcvcpetb[1] @513 0x00
ub1 kcvcpetb[2] @514 0x00
ub1 kcvcpetb[3] @515 0x00
ub1 kcvcpetb[4] @516 0x00
ub1 kcvcpetb[5] @517 0x00
ub1 kcvcpetb[6] @518 0x00
ub1 kcvcpetb[7] @519 0x00
BBED> set offset 500
OFFSET 500

BBED> dump /v —@500开始,4字节表示日志序号,4字节表示块号,2字节表示日志块中第几个字节,表示的是数据文件头的RBA信息
从数据块中计算出的RBA信息与print kcvfhckp中的一致,就不重复算了。
关于日志块大小,详见:http://blog.csdn.net/q947817003/article/details/11350359
File: /u01/oradata/bys3/user01.dbf (4)
Block: 1 Offsets: 500 to 1011 Dba:0x01000001
——————————————————-
6b000000 02000000 10000400 02000000 l k……………
00000000 00000000 00000000 00000000 l …………….
00000000 00000000 00000000 00000000 l …………….
省略。。。。
<16 bytes per line>

这里CHKPOINT_SCN信息是:
struct kcvcpscn, 8 bytes @484
ub4 kscnbas @484 0x001e6231
ub2 kscnwrp @488 0x0000
这三行就是检查点的SCN信息,kscnbas–0x001c8e12,kscnwrp–0x0000ub4 –实验有效的4个byte: 0x0000
scn计算方法:SCN=(SCN_WRP * 4294967296) + SCN_BAS –SCN的详细介绍及计算:http://blog.csdn.net/q947817003/article/details/11590983
所以此处的SCN就是:0x0000.001e6231;10进制SCN号为:1991217

RBA信息是:
struct kcvcprba, 12 bytes @500
ub4 kcrbaseq @500 0x0000006b –序号,
ub4 kcrbabno @504 0x00000002 –块号
ub2 kcrbabof @508 0x0010 –字节号
换算为十进制表示为:107号日志,2号块,16字节
与上一步DUMP数据文件信息得出的一致:
thread:1 rba:(0x6b.2.10)
–重做日志的地址0x6b.2.10–-> 107号日志,第2号块,第16个字节
###################################################################
7.执行EVENT事件的语句,OPEN数据库后立刻DUMP控制文件
注意事项:要把EVENT事件的语句执行上,不然实验所需数据不连贯哈哈
关于下面用到的10013/10015事件,分别是在Startup时跟踪事务恢复,在事务恢复后做Dump回退段头信息。
EVENT事件详见http://blog.csdn.net/q947817003/article/details/16359765
说明:–在这里用这两个语句不知道到底能不能DUMP出详细的REDO应用及回滚信息,从生成的TRACE文件来看有这方面信息,好像不太详细。。。
SYS@ bys3>alter session set events ‘10013 trace name context forever,level 1’;
Session altered.
SYS@ bys3>alter session set events ‘10015 trace name context forever,level 1’;
Session altered.
SYS@ bys3>alter database open;
Database altered.
SYS@ bys3>select value from v$diag_info where name like ‘Default%’;
VALUE
———————————————————————-
/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_1955.trc
另开一会话在OPEN数据库后立刻执行:
SYS@ bys3>alter session set events ‘immediate trace name controlf level 12’;
Session altered.
SYS@ bys3>select value from v$diag_info where name like ‘Default%’;
VALUE
——————————————————————————
/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_2108.trc

在OPEN过程中,ORACLE检查以下两项: 详见:http://blog.csdn.net/haibusuanyun/article/details/11271107
1.检查数据文件头中检查点计数(checkpoint CNT)是否与控制文件中检查点计数(checkpoint CNT)一致。以此确定数据文件是否来自恢复文件。
2.如果检查点计数检查通过,数据库进行第二次检查,检查数据文件头的开始SCN和控制文件中记录的该文件的结束SCN是否一致,如果控制文件中记录的结束SCN等于数据文件头的开始SCN,不需要实例恢复。
以上两次检查通过后,打开数据库,锁定数据文件,并将每个数据文件的结束SCN设置为无穷大。
##################################################################
8.分析OPEN时,通过ALERT日志查看的恢复过程–前滚
[oracle@bys3 ~]$ cat alert_bys3.log
Mon Dec 02 20:35:20 2013
alter database open
Beginning crash recovery of 1 threads –开始实例恢复
Started redo scan –开始扫描REDO日志
Completed redo scan –完成扫描REDO日志
read 202 KB redo, 104 data blocks need recovery –需要恢复的数据块104块,REDO日志202KB,按low cache rba–on disk rba来算是407-3=404个日志块,一个日志块大小是512字节,正好202KB。
Started redo application at
Thread 1: logseq 107, block 3 –这里可以看到,是从107号日志第3块开始应用REDO-与第3步中low cache rba:(0x6b.3.0)吻合
Recovery of Online Redo Log: Thread 1 Group 2 Seq 107 Reading mem 0
Mem# 0: /u01/oradata/bys3/redo02.log –所使用REDO日志文件,与第一步查询吻合。
Completed redo application of 0.16MB
Completed crash recovery at
Thread 1: logseq 107, block 407, scn 2011565 –完成实例恢复的位置,与第3步中on disk rba:(0x6b.197.0)吻合
104 data blocks read, 104 data blocks written, 202 redo k-bytes read –实例恢复涉及信息统计
Mon Dec 02 20:35:20 2013
LGWR: STARTING ARCH PROCESSES —-可以看到 实例恢复完成后,ARCH进程启动
Mon Dec 02 20:35:21 2013
ARC0 started with pid=19, OS id=2112
ARC0: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC0: STARTING ARCH PROCESSES
Thread 1 advanced to log sequence 108 (thread open)
Thread 1 opened at log sequence 108
Current log# 3 seq# 108 mem# 0: /u01/oradata/bys3/redo03.log
Successful open of redo thread 1 —-可以看到 实例恢复完成后,REDO日志启动
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Mon Dec 02 20:35:22 2013
SMON: enabling cache recovery
Mon Dec 02 20:35:22 2013
ARC1 started with pid=20, OS id=2116
Mon Dec 02 20:35:22 2013
ARC2 started with pid=21, OS id=2122
ARC1: Archival started
ARC2: Archival started
ARC1: Becoming the ‘no FAL’ ARCH
ARC1: Becoming the ‘no SRL’ ARCH
ARC2: Becoming the heartbeat ARCH
Mon Dec 02 20:35:23 2013
ARC3 started with pid=22, OS id=2126
还有段ALERT日志涉及回滚放在下一小节
################################################################
9.分析OPEN时,EVENT事件生成的TRACE中查看恢复过程–前滚
TRACE文件内容:
Thread 1 checkpoint: logseq 107, block 2, scn 1991217
cache-low rba: logseq 107, block 3 –这一段信息与MOUNT时DUMP控制文件的一样
on-disk rba: logseq 107, block 407, scn 1991565
start recovery at logseq 107, block 3, scn 0 –实例恢复起点: MOUNT时DUMP控制文件的low cache rba:(0x6b.3.0)

*** 2013-12-02 20:35:20.739
Started writing zeroblks thread 1 seq 107 blocks 407-414

*** 2013-12-02 20:35:20.745
Completed writing zeroblks thread 1 seq 107
==== Redo read statistics for thread 1 ====
Total physical reads (from disk and memory): 4096Kb
— Redo read_disk statistics –这个应该是实例恢复期间REDO读写统计
Read rate (ASYNC): 202Kb in 0.22s => 0.90 Mb/sec –REDO的速度-202KB与ALERT日志中对应
Longest record: 17Kb, moves: 0/287 (0%)
Longest LWN: 18Kb, moves: 0/99 (0%), moved: 0Mb
Last redo scn: 0x0000.001e638c (1991564) –最后一个REDO的SCN:与On-Disk RBA的SCN是1991565差1
———————————————-
—– Recovery Hash Table Statistics ———
Hash table buckets = 262144
Longest hash chain = 1
Average hash chain = 104/104 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 1120/1224 = 0.9
———————————————-
*** 2013-12-02 20:35:20.749
KCRA: start recovery claims for 104 data blocks
*** 2013-12-02 20:35:20.781
KCRA: blocks processed = 104/104, claimed = 104, eliminated = 0
*** 2013-12-02 20:35:20.783
Recovery of Online Redo Log: Thread 1 Group 2 Seq 107 Reading mem 0
*** 2013-12-02 20:35:20.815
Completed redo application of 0.16MB –与ALERT中对照
*** 2013-12-02 20:35:20.944
Completed recovery checkpoint –可以看到 实例恢复完后做了检查点
—– Recovery Hash Table Statistics ———
Hash table buckets = 262144
Longest hash chain = 1
Average hash chain = 104/104 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 1224/1224 = 1.0
———————————————-
Recovery sets nab of thread 1 seq 107 to 407 with 8 zeroblks
##################################################################
10.OPEN数据库时,通过ALERT日志及EVENT事件生成的TRACE中信息解析实例恢复的回滚
能力有限,解析不了,留着以后解决吧。
ALERT日志中回滚信息:
[1955] Successfully onlined Undo Tablespace 2. —
Undo initialization finished serial:0 start:985058364 end:985058674 diff:310 (3 seconds) –从这句看应该是有回滚操作,能力有限,没更好解释。。。
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is AL32UTF8
Archived Log entry 77 added for thread 1 sequence 107 ID 0xc82cb897 dest 1:
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
Mon Dec 02 20:35:24 2013
QMNC started with pid=23, OS id=2130
ARC3: Archival started
ARC0: STARTING ARCH PROCESSES COMPLETE
Completed: alter database open
#############################
EVENT事件生成的TRACE中信息
*** 2013-12-02 20:35:22.989
Acq rollback segment SYSTEM
Rec rollback segment _SYSSMU1_3056155133$
Recovering transaction (1, 21) –看这里好像是SYSTEM回滚段做的事务恢复
Marking transaction (1, 21) dead
Rec rollback segment _SYSSMU2_3692097322$
Rec rollback segment _SYSSMU3_3366438251$
Rec rollback segment _SYSSMU4_3660460897$
Rec rollback segment _SYSSMU5_1917899003$
Rec rollback segment _SYSSMU6_3107841501$
Rec rollback segment _SYSSMU7_1420906157$
Rec rollback segment _SYSSMU8_2178365988$
Rec rollback segment _SYSSMU9_1689884801$
Rec rollback segment _SYSSMU10_3239467560$
*** 2013-12-02 20:35:23.225
Recovering transaction (1, 21) —-这个好像是回滚的第一步中未提交的事务,不知道具体如何查询验证
Marking transaction (1, 21) dead
Acq rollback segment _SYSSMU1_3056155133$
Acq rollback segment _SYSSMU2_3692097322$
Acq rollback segment _SYSSMU3_3366438251$
Acq rollback segment _SYSSMU4_3660460897$
Acq rollback segment _SYSSMU5_1917899003$
Acq rollback segment _SYSSMU6_3107841501$
Acq rollback segment _SYSSMU7_1420906157$
Acq rollback segment _SYSSMU8_2178365988$
Acq rollback segment _SYSSMU9_1689884801$
Acq rollback segment _SYSSMU10_3239467560$
kwqmnich: current time:: 12: 35: 23: 0
kwqmnich: instance no 0 repartition flag 1
kwqmnich: initialized job cache structure
*** 2013-12-02 20:35:24.574
ktsmgtur(): TUR was not tuned for 25928 secs
ktsmg_advance_slot(): MMNL advances slot after 25928 seconds
################################################################################
11.分析OPEN后的控制文件信息–能力有限分析较少
TRACE文件内容
DATABASE ENTRY
***************************************************************************
(size = 316, compat size = 316, section max = 1, section in-use = 1,
last-recid= 0, old-recno = 0, last-recno = 0)
(extent = 1, blkno = 1, numrecs = 1)
11/14/2013 14:23:19
DB Name “BYS3”
Database flags = 0x00404001 0x00001200
Controlfile Creation Timestamp 11/14/2013 14:23:21
Incmplt recovery scn: 0x0000.00000000
Resetlogs scn: 0x0000.00000001 Resetlogs Timestamp 11/14/2013 14:23:19
Prior resetlogs scn: 0x0000.00000000 Prior resetlogs Timestamp 01/01/1988 00:00:00
Redo Version: compatible=0xb200000
#Data files = 4, #Online files = 4
Database checkpoint: Thread=1 scn: 0x0000.001eb1b0 –检查点已经更新
Threads: #Enabled=1, #Open=1, Head=1, Tail=1
enabled threads: 01000000 00000000 00000000 00000000 00000000 00000000
Max log members = 5, Max data members = 1
Arch list: Head=3, Tail=3, Force scn: 0x0000.001b6c94scn: 0x0000.00000000
Activation ID: 3358374039
SCN compatibility 1
Auto-rollover enabled
Controlfile Checkpointed at scn: 0x0000.001eb212 12/02/2013 20:35:25
thread:0 rba:(0x0.0.0)
enabled threads: 00000000 00000000 00000000 00000000 00000000 00000000

***************************************************************************
CHECKPOINT PROGRESS RECORDS
***************************************************************************
(size = 8180, compat size = 8180, section max = 4, section in-use = 0,
last-recid= 0, old-recno = 0, last-recno = 0)
(extent = 1, blkno = 2, numrecs = 4)
THREAD #1 – status:0x2 flags:0x0 dirty:43
low cache rba:(0x6c.3.0) on disk rba:(0x6c.76.0) –on disk rba已经递增
on disk scn: 0x0000.001eb212 12/02/2013 20:35:24 –on disk scn已经递增
resetlogs scn: 0x0000.00000001 11/14/2013 14:23:19
heartbeat: 833141767 mount id: 3360007946

ORACLE实例恢复过程详细分析–使用dump、BBED等多种工具结合分析

ORA-4031错误
ORA-04031错误就是因不能在分配连续的内存,可能是共享池内存碎片严重,也可能是确实内存不足。
引起这种情况的原因有:频繁更解析–需要内存空间多,并且容易产生更严重的内存碎片。
session_cached_cursors太高,被缓存的游标过多–占用大量library cache内存,有可能引发ORA-4031。

共享池碎片产生举例:
在报ORA-4031错误的时候,有可能使用下面的SQL语句查看,发现可用的内存还是足够大的,
SQL> select POOL,NAME,BYTES from v$sgastat whereNAME=’free memory’;
事实上,在Oracle发出4031错误之前,已经释放了不少recreatable类型的chunk了,因此会产生很多可用内存。但是这些可用的chunk中,没有一个chunk能够以连续的物理内存提供所需的内存空间
在shared pool中有一块保留区域,通过参数shared_pool_reserved_size设置,默认是shared pool空间的5%。
SQL>show parameter shared_pool_reserved_size
SQL>select request_misses from v$shared_pool_reserved;
这个参数反映了无法从保留区域获得足够大空间的chunk的总次数,尽量让这个参数为0.
对于非常大的对象,一般从这个区域中分配空间
这是一块独立管理的区域,这个区域中的chunk不会挂接到普通区域的链表中,普通区域的chunk也不会挂接到这个区域的链表中

SQL语句要缓存在共享池CHUNK中,假设SQL语句的文本、执行计划共需要4K。
在找可用CHUNK时,首先进入相应bucket进去查找,
如未找到4K大小CHUNK,则转向下一个非空bucket,假设找到一个5K的CHUNK;
此时会4K用来存放此SQL语句相关文本、执行计划,剩余1K成为一个新CHUNK并进入相应的bucket,及FREE LIST列表。
长此以往,可能产生大量1K/2K等小CHUNK,总空间很大,但是如果SQL语句需要比如4K的CHUNK,就无法请求到所需的CHUNK,产生共享池碎片,引起ORA-04031错误。
查看共享池中CHUNK SIZE情况,如果<1K比较多,可能就碎片严重。 —通常每个bucket上的chunk多于2000个,就认为共享池碎片过多。
col sga_heap format a15
col size format a10
select KSMCHIDX “SubPool”, ‘sgaheap(‘||KSMCHIDX||’,0)’sga_heap,ksmchcom ChunkComment,
decode(round(ksmchsiz/1000),0,’0-1K’, 1,’1-2K’, 2,’2-3K’,3,’3-4K’,
4,’4-5K’,5,’5-6k’,6,’6-7k’,7,’7-8k’,8,
‘8-9k’, 9,’9-10k’,’> 10K’) “size”,
count(*),ksmchcls Status, sum(ksmchsiz) Bytes
from x$ksmsp
where KSMCHCOM = ‘free memory’
group by ksmchidx, ksmchcls,
‘sga heap(‘||KSMCHIDX||’,0)’,ksmchcom, ksmchcls,decode(round(ksmchsiz/1000),0,’0-1K’,
1,’1-2K’, 2,’2-3K’, 3,’3-4K’,4,’4-5K’,5,’5-6k’,6,
‘6-7k’,7,’7-8k’,8,’8-9k’, 9,’9-10k’,’> 10K’);
###################

前台进程在共享池中查找CHUNK步骤:
1.首先查找子堆 free list
2.查找子堆lru
3.从父堆中分配chunk,做为子堆新 extent
4.父堆查找free list
5.父堆查找LRU
6.使用hide free space
7.如以上步骤失败,报0RA-04031
父堆需要持有shared pool latch
子堆的操作,有mutex / library cache pin保护

模拟ORA-04031错误:
首先要将修改open_cursors 参数
BYS@ bys3>show parameter cursors
NAME TYPE VALUE
———————————— ———– ——————————
open_cursors integer 50
session_cached_cursors integer 2
BYS@ bys3>alter system set open_cursors =50000;
System altered.
BYS@ bys3>show parameter shared_pool
NAME TYPE VALUE
———————————— ———– ——————————
shared_pool_reserved_size big integer 7M
shared_pool_size big integer 176M
重新登陆会话:
只打开游标,不关闭:select deptno from dept where deptno= 这语句的对象字段要能执行
declare
msql varchar2(100);
mcur number;
mstat number;
jg varchar2(2000);
cg number;
begin for i in 1..10000 loop
mcur:=dbms_sql.open_cursor;
msql:=’select deptno from dept where deptno=’||i;
dbms_sql.parse(mcur,msql,dbms_sql.native);
mstat:=dbms_sql.execute(mcur);
end loop;
end;
/
报错:
declare
*
ERROR at line 1:
ORA-04031: unable to allocate 16 bytes of shared memory (“sharedpool”,”unknownobject”,”SQLA”,”tmp”)
ORA-06512: at “SYS.DBMS_SQL”, line 1199
ORA-06512: at line 10
也可能报错:主要是unable to allocate1040 bytes 这里的有时不一样。上一个16bytes可能是语句确实需要16字节,但是从父堆分配区,需要按一个CHUNK分配,具体是多大CHUNK,没显示出来。
declare
*
ERROR at line 1:
ORA-04031: unable to allocate 1040 bytes of shared memory (“sharedpool”,”select
o”,”PLDIA^191e0a8d”,”PAR.C:parapt:Page”)
ORA-06508: PL/SQL: could not find program unit being called:”SYS.DBMS_SQL”
ORA-06512: at line 8
执行其它查询也报错:
BYS@ bys3>select * from dept where deptno=44;
select * from dept where deptno=44
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 2
ORA-04031: unable to allocate 136 bytes of shared memory (“sharedpool”,”select /*+ rule */
bucket_cn…”,”SQLA^337fc737″,”kccdef: qkxrMemAlloc”)

Elapsed: 00:00:10.99
BYS@ bys3>show parameter shared_pool
ORA-04031: unable to allocate 16 bytes of shared memory (“sharedpool”,”unknown
object”,”KGLH0^92c529c4″,”kglHeapInitialize:temp”)

警告日志中也可以看到大量的报错日志:
Mon Feb 03 20:20:44 2014
Errors in file /u01/diag/rdbms/bys3/bys3/trace/bys3_mmon_10113.trc (incident=138413):
ORA-04031: unable to allocate 16 bytes of shared memory (“sharedpool”,”unknownobject”,”KGLH0^ca490471″,”kglHeapInitialize:temp”)
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Errors in file /u01/diag/rdbms/bys3/bys3/trace/bys3_mmon_10113.trc (incident=138414):
ORA-04031: unable to allocate 16 bytes of shared memory (“sharedpool”,”unknownobject”,”KGLH0^ca490471″,”kglHeapInitialize:temp”)
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
[oracle@bys3 ~]$ tail -n 50 alert_bys3.log
Mon Feb 03 20:20:14 2014
Errors in file /u01/diag/rdbms/bys3/bys3/trace/bys3_m000_10679.trc (incident=134643):
ORA-04031: unable to allocate 16 bytes of shared memory (“sharedpool”,”unknownobject”,”KKSSP^37″,”kglseshtSegs”)
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Errors in file /u01/diag/rdbms/bys3/bys3/trace/bys3_m000_10679.trc:
ORA-04031: unable to allocate 16 bytes of shared memory (“sharedpool”,”unknownobject”,”KKSSP^37″,”kglseshtSegs”)
…………………………
Errors in file /u01/diag/rdbms/bys3/bys3/trace/bys3_cjq0_10175.trc:
ORA-00604: error occurred at recursive SQL level 1
ORA-04031: unable to allocate 528 bytes of shared memory (“sharedpool”,”PROPS$”,”PLDIA^191e0a8d”,”PAR.C:parapt:Page”)

4031错误临时解决方案是:杀掉一部分会话或者flush shared_pool;
SYS@bys3>select sid,count(*) from v$open_cursor group by sid;
SID COUNT(*)
———- ———-
30 7
1 2
28 1
13 3
31 4
14 2
35 3014
33 3
15 7
16 5
select sid,machine from v$session;
根据查出的机器来划分,KILL掉不太重要的会话

以SYS登陆,做flushshared_pool;
—不建议,刷新共享池后,所有的SQL语句都需要重新解析,对共享池中LATCH的争用,以及大量更解析会消耗大量CPU资源。
SYS@ bys3>alter system flush shared_pool;
System altered.
但是之后会面临大量正常SQL语句的第一次执行的硬解析。。
过后仍需要找出产生大量硬解析的SQL语句进行优化。

共享池之十:模拟ORA-4031错误

解析分为硬解析和软解析和软软解析,SQL语句第一次解析时必须进行硬解析

还有一种是结果集缓存—无解析,详见:结果集缓存

一句话说明硬解析与软解析的区别是:

硬解析=需要生成执行计划 软解析=不需要生成执行计划

在Oracle中存在两种类型的SQL语句,一类为DDL语句,不共享使用,也就是每次执行都需要进行硬解析。还有一类就是DML语句,会进行硬解析或软解析。

硬解析变成软解析:绑定变量

软解析变成软软解析:设置session_cached_cursors,详见本文最后。

软软解析参数session_cached_cursors的参考值
select owner,name from v$db_object_cache where child_latch=1;显示library cache中那些对象被缓存,以及对象的尺寸

session_cached_cursors占用的内存:会话退出会释放,或者达到达到最大值后,最早、早少使用的会被释放。

session_cached_cursors参数的设置: –来自周亮–ORACLE DBA实战攻略。

SYS@ bys3>show parameter session_cached 11G中默认值是50

NAME TYPE VALUE

—————————————————————————–

session_cached_cursors integer 50

SYS@ bys3>select a.name,b.value from v$statname a,v$sesstat b where a.statistic#=b.statistic# and a.name in(‘session cursor cache hits’,’session cursor cache count’,’parse count (total)’) and b.sid=(select c.sid from v$mystat c where rownum=1);

NAME VALUE

————————————————————————–

session cursor cachehits 32

session cursor cachecount 4

parse count(total) 43

session cursor cache count表示指定会话缓存的游标数,session_cached_cursors参数是系统当前每个会话最多能缓存的游标数。

session cursor cache count小于session_cached_cursors,不用增加session_cached_cursors大小。如相等,则有可能需要增加。

session cursor cache hits 表示从UGA中命中的次数–软软解析次数。

parse count (total)指定会话的总解析次数。

如果session cursor cache hits接近parsecount (total),无需调整session_cached_cursors。

如果session cursor cache hits远小于parsecount(total),则可能需要调整session_cached_cursors。

session_cached_cursors对所有会话生效,如果需要调优的会话占所有会话比例很小,调整意义不大。

–注意session_cached_cursors是静态参数,调整后要重启库才生效。

SYS@ bys3>alter system set session_cached_cursors=11;
alter system set session_cached_cursors=11
*
ERROR at line 1:
ORA-02096: specified initialization parameter is not modifiable with this option

绑定变量
oracle 能够重复利用执行计划的方法就是采用绑定变量。

绑定变量的实质就是用于替代sql语句中的常量的替代变量。绑定变量能够使得每次提交的sql语句都完全一样。

绑定变量只是起到占位的作用,同名的绑定变量并不意味着在它们是同样的,在传递时要考虑的是传递的值与绑定变量出现顺序的对位,而不是绑定变量的名称。

绑定变量是在通常情况下能提升效率,非正常的情况如下:

在字段(包括字段集)建有索引,且字段(集)的集的势非常大(也就是有个值在字段中出现的比例特别的大)的情况下,使用绑定变量可能会导致查询计划错误,因而会使查询效率非常低。这种情况最好不要使用绑定变量。

但是并不是任何情况下都需要使用绑定变量,下面是两种例外情况:

1.对于隔相当一段时间才执行一次的SQL语句,这是利用绑定变量的好处会被不能有效利用优化器而抵消

2.数据仓库的情况下。

绑定变量不能当作嵌入的字符串来使用,只能当作语句中的变量来用。不能用绑定变量来代替表名、过程名、字段名等.

从效率来看,由于oracle10G全面引入CBO,因此,在10G中使用绑定变量效率的提升比9i中更为明显。

绑定变量窥视:Bind Peeking–字段分布均匀时有利
Bind Peeking 就是当在WHERE条件中使用绑定变量的时候,CBO会根据第一次使用的真实变量值来生成一个执行计划。在这个cursor的整个生命周期中,CBO不会再对相同的SQL进行hardparse。

优点:如果索引字段的值是均匀分布的,hardparse就降低了,性能提高。

缺点:如果字段分布不均匀,并且第一次使用值不具有普遍性,那么执行计划就将非常糟糕。

Oracle11g 提供了一个新特性,AdpativeCursorSharing,或者叫 Extended Cursor Sharing,来解决这个问题。他的核心思想是,当某个字段的histogram提供了数据不均匀的信息,CBO会在实际使用不同值的时候,尝试重新生成更合适的执行计划。

通过隐含的参数来调整数据库默认的bind peeking行为:_OPTIM_PEEK_USER_BINDS。

关闭Bind Variable Peeking,可以设置该参数为False —-要重启数据库。

SQL>alter sessionset”_optim_peek_user_binds”=false

绑定变量分级–bind graduation及bind-mismatch导致高版本问题
bind_mismatch一般是由于bind value的长度不同导致bindbuffer无法重用,最终导致cursor无法重用。
根本的原因在于:Oracle数据库引擎应用了绑定变量分级,即根据绑定变量的长短划分为4级,比如varchar2(32)和varchar2(33)属于不同级别。
四个级别的划分是:
0~32
32~128
129~2000
2001~
当表上有数十上百个varchar2类型的列时候,会比较常见因为bind graduation导致的bind-mismatch,即产生N多无法共享的子游标。
子游标过多会对SQL parse有影响。
针对一些特别的表或者查询列特别多的SQL,可以通过给字符串变量绑定固定的长度,如to_char(4000),来避免因为bind graduation导致child cursor过多的问题.

例 如:对于字符类型的字段,进行绑定变量的时候,第一次会使用32字节的BUFFER,如果该值小于32字节的话,第二次执行这个SQL的时候,如果小于 32字节,那么可以共享这个CURSOR,如果大于,就无法共享,原因就是BIND_MISMATCH,此时会产生一个子CURSOR,同时分配128字节的BIND BUFFER,以此类推。
select count(*) from v$sql_shared_cursor where sql_id=’9rwd4wkwm4bsy’ andBIND_MISMATCH=’Y’ ;
COUNT(*)
———-
120

可以通过v$sql_bind_capture视图查看一下每次绑定变量的值:
select position,LAST_CAPTURED,datatype_string,value_string fromv$sql_bind_capture where sql_id=’9rwd4wkwm4bsy’ and rownum<50;

正常情况不会产生这么大量的子CURSOR。但是由于一些BUG,会导致问题。
如果没有补丁,一个临时性的解决方案,设置一个较大的BUFFER
SQL>ALTER SESSION SET EVENTS ‘10503 trace name context level<bufferlength>, forever’;

而这些具体的内容,可以通过视图来查看。查看上述的共享父游标对于的bind_metadata
selects.child_number,m.position,m.max_length,
decode(m.datatype,1,’VARCHAR2′,2,’NUMBER’,m.datatype)as datatype
from v$sql s,v$sql_bind_metadata m
where s.sql_id=’94ka9mv232yxb’
and s.child_address=m.address;
CHILD_NUMBER POSITION MAX_LENGTH DATATYPE
———— ———- ———————————————-
0 3 32 VARCHAR2
0 2 32 VARCHAR2
0 1 22 NUMBER
1 3 32 VARCHAR2
1 2 128 VARCHAR2
1 1 22 NUMBER
从绑定变量四个级别来看,最多生成4个子游标。但是为什么AWR报表中SQL ordered by Version Count的version count能高达好几十,甚至几百呢?而且不能共享的原因都是因为bind_mismatch.

关于:cursor_sharing
根据oracle官方建议在11g中不推荐使用cursor_sharing=SIMILAR,其实在所有版本中都不推荐,设置为该值很容易导致高版本问 题.而且该值会出现莫名其妙的,无法解释的高版本问题.而且根据oracle相关文档,在即将发布的12c版本中,将除掉SIMILAR值.对于客户库的 该问题,因为很多sql未绑定参数,为了减少硬解析,建议在业务低谷时设置cursor_sharing=FORCE,并刷新sharedpool.

如果cursor_sharing 参数是设置为similar的,这样会将SQL 中的谓词值自动用变量来代替。这样会增加cursor的数量。
为了减少cursor对library cache的占用,先将cursor_shring 参数改成了默认的exact模式。
这样version_count 会减少很多,但是硬解析的次数也会增加,可能会增加Library Cache Latch等待。
cursor_sharing的实验可以参考DAVE的博客:http://blog.csdn.net/tianlesoftware/article/details/6551723

共享池之九:绑定变量与session_cached_cursors

先来张大图:

结合上图来说明一下解析的各个步骤涉及的锁。

软解析、硬解析、软软解析区别的简单说明:
为了将用户写的sql文本转化为oracle认识的且可执行的语句,这个过程就叫做解析过程。

解析分为硬解析和软解析,SQL语句第一次解析时必须进行硬解析

一句话说明硬解析与软解析的区别是:
硬解析=需要生成执行计划 软解析=不需要生成执行计划

在Oracle中存在两种类型的SQL语句,一类为DDL语句,不共享使用,也就是每次执行都需要进行硬解析。还有一类就是DML语句,会进行硬解析或软解析。

硬解析变成软解析:绑定变量

软解析变成软软解析:设置session_cached_cursors,详见

图中涉及的各结构简单介绍:
涉及的各结构的简单介绍: 详见:

父游标:保存HASH值,SQL文本–相同SQL语句,就只有一个父游标

父游标里主要包含两种信息:sql文本以及优化目标。父游标在第一次打开时被锁定,直到其他所有的session都关闭该游标后才被解锁。当父游标被锁定的时候是不能被交换出librarycache的,只有在解锁以后才能被交换出library cache。父游标被交换出内存时父游标对应的所有子游标也被交换出library cache。

子游标:一个父游标下会有多个子游标,各个子游标的执行计划不一样–多版本.一个父下必有一个子游标,可以有多个子游标。

子游标包括游标所有的信息,比如具体的执行计划、绑定变量等。子游标随时可以被交换处library cache,当子游标被交换出library cache时,oracle可以利用父游标的信息重新构建出一个子游标出来,这个过程叫做reload(重载)。

父HANDLE,里面有父游标堆0的地址。。

父游标堆0:有指向一个或多个子游标的HANDLE够句柄地址

子游标的HANDLE:有子游标堆0地址

子游标堆0:有SQL语句依赖关系,并指向子游标的堆6

子游标堆6:存有SQL语句的执行计划

SQL语句在Library cache执行的第一次检查过程:
1.通过语法语义权限等检查的SQL语句进入Library cache
2.将SQL文本转化为ASCII值(大小写ASCII不同)并进行hash函数的运算
4.得到一个HASH值对应到hash bucket的号码
################以上检查通过后,进入以下解析过程

软软解析:
–通过设置session_cached_cursors参数实现-
SQL执行=3次(可以不是一个会话执行的SQL),堆6的DS-堆描述符地址被放入UGA(属于PGA)–LOCK变为1-NULL标记语句为缓存并保证内存不被释放(堆6释放堆0才能释放)。
也就是SQL执行3次,被缓存。第四次,就是软软解析了。
–优化目标:命中率90%以上。
会话发起SQL,会首先在User Global Area中查找CURSOR信息。
此时,在父游标handle,子游标handle和子游标堆6上使用NULL 1。

####################################

软解析:
1.获得library cacheLatch —如未获得将产生:Latch:library cache
2.获得library cache lock,检索bucket上的父游标handle,得到所指向的父游标堆0-LCO的内存地址。
3.获得library cache pin,读取父游标堆0-LCO,得到子游标handle地址。
4.获得library cache lock,检索子游标handle,得到所指向的子游标堆0-子LCO的内存地址。
5.获得library cache pin,读取子游标堆0-子LCO从而得到子游标堆6地址。
6.读取子游标堆6,得到SQL执行计划。
###找到child lco后,增加parsecount(total)统计值。
SQL开始执行:此时以共享模式获得library cache lock和library cache pin,并执行SQL。
FETCH阶段:执行完成进入FETCH阶段,SQLCURSOR将library cache lock转换为null模式,释放library cache pin。
###############################################################

在尝试软解析时:
–如果未检索到相同的父游标LCO或子游标LCO时,发生硬解析。
–如果子游标堆6上不能加共享library cachepin或者child lco中信息不完整,需要重建执行计划–记录为硬解析。

硬解析:
如果未检索到相同的父游标LCO或子游标LCO时,发生硬解析。进程会一直持有library cache latch,直到硬解析结束为止。
1.获取shared pool latch,从freelist的bucket上查找合适大小的CHUNK。
不存在大小合适的CHUNK会分割大CHUNK,剩余的会再进入相应的BUCKET。
如 果不能从free list的bucket上查找到合适大小的CHUNK,则进入 lru list;如果仍不能获取到CHUNK,则从shared pool剩余内在中分配。如果CURSOR达到 _shared_pool_reserved_min_alloc隐含参数的大小标准(11.2.0.4中是4400),则从保留池中分配CHUNK;如 果这些分配CHUNK操作都失败,报错:ORA-04031。如bucket列表过长或者碎片严重,产生latch:shared pool争用。

2.分配到CHUNK后。获得library cachelock–独占模式,创建父游标handle
3.获得library cache pin,创建父游标堆0-父LCO的信息。–library cache lock转为NULL
4.获得library cache lock,创建子游标handle
5.获得library cache pin,创建子游标堆0-子LCO的信息。
6.library cache pin,创建子游标堆6-执行计划的信息(通过优化器创建一个最优的执行计划,这个过程会根据数据字典里面记录的对象的统计信息,来计算最优的执行计划,这一步涉及的运算量很大,最耗CPU资源)。
SQL开始执行:此时以共享模式获得library cache lock和library cache pin,并执行SQL。
FETCH阶段:执行完成进入FETCH阶段,SQLCURSOR将library cache lock转换为null模式,释放library cache pin。

关于MUTEX与图中librarycache Latch/PIN/LOCK的对应:
关于MUTEX,可以简单的把library cache Latch/PIN/LOCK当做MUTEX的不同模式来套入此步骤。

在10G中,Mutex主要保护 handle和LCO—替代library cache PIN/LOCK

在11G中,Mutex可以保护bufket上链表,handle和LCO—替代library cache Latch/PIN/LOCK

句柄上访问竞争:Cursor:mutex 堆的访问竞争:Cursor:pin

解析时MUTEX的相关争用

1、相关锁

(1)、计算HASH值,找到Bucket,搜索HASH链表,查找句柄。

LIbrary Cache Latch(11G后被Mutex取代)

(2)、在父游标句柄中查找父游标堆0

mutex(取代Library cache lock latch) ,Library cache lock

(3)、在父游标堆0中,查找子游标句柄。

两次mutex。两种类型的Mutex。取代了Librarycache pin latch和Library cache pin 。

(4)、在子游标句柄中,查找子游标堆0地址。

mutex(取代Library cache lock latch) ,Library cachelock

(5)、在子游标堆0中,查找子游标堆6地址。

一次mutex。取代了Librarycache pin latch和Library cache pin 。

(6)、在子游标堆6中,读取SQL执行计划。

一次mutex。取代了Librarycache pin latch和Library cache pin 。

 

共享池之八:软解析、硬解析、软软解析 详解一条SQL在library cache中解析涉及的锁