[讨论话题]redolog switch会发生完全检查点还是增量检查点

coloredice · 发表于 2013-5-8 09:12

www_xylove 发表于 2013-5-7 23:46
晶晶小妹的关于“晶晶实验九之详细论述增量检查点篇”应该是经典之作了。
http://bbs.chinaunix.net/threa ...

“实例崩溃后,再次启动数据库,oracle会到控制文件中读取low cache rba,这就是检查点位置.从此处开始应用重做信息,应用到on disk rba处.on disk rba是磁盘中重做日志文件的最后一条重做记录的rba.”
还是这个问题，如何证明是最后一条，会不会on disk rba有不是最后一条的时候。还有就是low cache rba如果是由检查点写入的话，检查点又是3s触发一次，会不会3s中dirty buffer已经写入数据文件而此时low cache rba还没更新呢，此时恢复的起始位置还是否是low cache rba呢。期待证明

broadrange · 发表于 2013-5-8 11:40

本帖最后由 broadrange 于 2013-5-8 11:44 编辑

guoyJoe 发表于 2013-5-7 09:02
这个结论不对吧，没有弄清楚完全检查点和增量检查点的基本概念。

给出试验结果，我的结论也要修正一下，就是在下一组日志还是Active的状态下会先做完全检查点，再做一次增量检查点，否则只做增量检查点。
Oracle: 11.2.0.1.0

1. 创建一个表aaa，向表中插入几条数据，为了使手工切换日志后日志状态为Active状态，不要commit
2. 打开检查点向alert中写日志的开关
3. 反复手工切换日志，并用v$log查看日志的状态
4. 查看alert中日志在不同情况下的切换时检查点的日志

create table aaa (a varchar2(100));
alter system set log_checkpoints_to_alert=true scope=both;

18:57:46 SYS@orcl>select * from v$log;

GROUP# THREAD#  SEQUENCE#    BYTES  BLOCKSIZE MEMBERS ARC STATUS          FIRST_CHANGE# FIRST_TIM NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- ------------ ---------
      1       1       278 52428800       512       1 YES INACTIVE             3212655 07-MAY-13    3212680 07-MAY-13
      2       1       280 52428800       512       1 NO  CURRENT             3212692 07-MAY-13 2.8147E+14
      3       1       279 52428800       512       1 YES INACTIVE             3212680 07-MAY-13    3212692 07-MAY-13
当前日志状态

18:57:52 SCOTT@orcl>insert into aaa values ('ljljljlsjf');

1 row created.
插入数据未commit

18:58:10 SYS@orcl>alter system switch logfile;

System altered.

18:58:54 SYS@orcl>select * from v$log;

GROUP# THREAD#  SEQUENCE#    BYTES  BLOCKSIZE MEMBERS ARC STATUS          FIRST_CHANGE# FIRST_TIM NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- ------------ ---------
      1       1       281 52428800       512       1 NO  CURRENT             3214042 07-MAY-13 2.8147E+14
      2       1       280 52428800       512       1 YES ACTIVE                3212692 07-MAY-13    3214042 07-MAY-13
      3       1       279 52428800       512       1 YES INACTIVE             3212680 07-MAY-13    3212692 07-MAY-13

Tue May 07 18:58:54 2013
Beginning log switch checkpoint up to RBA [0x119.2.10], SCN: 3214042
Thread 1 advanced to log sequence 281 (LGWR switch)
  Current log# 1 seq# 281 mem# 0: /u01/app/oracle/oradata/orcl/redo01.log
Tue May 07 18:58:54 2013
Archived Log entry 291 added for thread 1 sequence 280 ID 0x4b78e9f7 dest 1:
没有检查点结束的日志，可以看出是以异步方式做的检查点

18:58:58 SYS@orcl>alter system switch logfile;

System altered.

18:59:07 SYS@orcl>select * from v$log;

GROUP# THREAD#  SEQUENCE#    BYTES  BLOCKSIZE MEMBERS ARC STATUS          FIRST_CHANGE# FIRST_TIM NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- ------------ ---------
      1       1       281 52428800       512       1 YES ACTIVE                3214042 07-MAY-13    3214048 07-MAY-13
      2       1       280 52428800       512       1 YES ACTIVE                3212692 07-MAY-13    3214042 07-MAY-13
      3       1       282 52428800       512       1 NO  CURRENT             3214048 07-MAY-13 2.8147E+14
再次切换日志，两个日志组状态为Active

Tue May 07 18:59:07 2013
Beginning log switch checkpoint up to RBA [0x11a.2.10], SCN: 3214048
Thread 1 advanced to log sequence 282 (LGWR switch)
  Current log# 3 seq# 282 mem# 0: /u01/app/oracle/oradata/orcl/redo03.log
Tue May 07 18:59:07 2013
Archived Log entry 292 added for thread 1 sequence 281 ID 0x4b78e9f7 dest 1:
没有检查点结束的日志，可以看出是以异步方式做的检查点

18:59:15 SYS@orcl>/

GROUP# THREAD#  SEQUENCE#    BYTES  BLOCKSIZE MEMBERS ARC STATUS          FIRST_CHANGE# FIRST_TIM NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- ------------ ---------
      1       1       281 52428800       512       1 YES ACTIVE                3214042 07-MAY-13    3214048 07-MAY-13
      2       1       280 52428800       512       1 YES ACTIVE                3212692 07-MAY-13    3214042 07-MAY-13
      3       1       282 52428800       512       1 NO  CURRENT             3214048 07-MAY-13 2.8147E+14

18:59:48 SYS@orcl>alter system switch logfile;

System altered.
第三次切换日志

Tue May 07 18:59:57 2013
Thread 1 cannot allocate new log, sequence 283
Checkpoint not complete
  Current log# 3 seq# 282 mem# 0: /u01/app/oracle/oradata/orcl/redo03.log
Tue May 07 18:59:59 2013
Completed checkpoint up to RBA [0x119.2.10], SCN: 3214042
Beginning log switch checkpoint up to RBA [0x11b.2.10], SCN: 3214076
Thread 1 advanced to log sequence 283 (LGWR switch)
  Current log# 2 seq# 283 mem# 0: /u01/app/oracle/oradata/orcl/redo02.log
Tue May 07 18:59:59 2013
Archived Log entry 293 added for thread 1 sequence 282 ID 0x4b78e9f7 dest 1:
第三次切换日志，无法分配新的日志，报checkpoint not complete，做了同步的完全检查点，接着再做了日志切换的增量检查点这里的同步的完全检查点应该才是Oracle文档中描述的Thread checkpoint之一的Online redo log switch

yubo811127 · 发表于 2013-5-8 12:15

huanhuanlove 发表于 2013-5-6 16:32
http://www.killdb.com/2011/11/09/%E8%AF%A6%E8%A7%A3oracle-checkpoint.html

coloredice · 发表于 2013-5-8 12:35

mlx_861201 发表于 2013-5-8 09:07
的确，谢谢你的阅读和提醒

www_xylove · 发表于 2013-5-8 22:36

1.完全检查点由shutdown immediate,alter system checkpoint触发，dbwr将数据库所有的脏块写入数据文件，ckpt进程则更新控制文件和数据文件头部信息，保证控制文件SCN与数据文件SCN是一致的。
2.增量检查点是每3秒检查dbwr进程写脏块的进度，并将检查点位置，即rba更新到控制文件；另外就是ckpt进程通知dbwr写脏块也是。

请教guoyJoe ，难道只有完全检查点才同时更新控制文件与数据文件的头部信息吗？增量检查点，其他检查点呢？谢谢。

hexel · 发表于 2013-5-9 01:27

本帖最后由 hexel 于 2013-5-9 10:14 编辑

郭老师，小弟带着问题来的，求指导！

日志切换检查点是一种特殊的检查点：考虑到系统负载，日志切换时候，oracle并不立即把之前的重做日志保护的脏数据写入数据文件。

实验如下(参考了roger大师的实验

)：

实验环境：11gR2

查看重做日志文件：

SYS AS SYSDBA > select GROUP#,THREAD#,SEQUENCE#,STATUS,FIRST_CHANGE#,NEXT_CHANGE# from v$log;

----------|----------|----------|----------------|-------------|------------

1| 1| 37|INACTIVE | 4537416| 4537426

2| 1| 38|INACTIVE | 4537426| 4537434

3| 1| 39|CURRENT | 4537434| 2.8147E+14

查看增量检查点信息：

SYS ASSYSDBA > SELECTCPLRBA_SEQ,CPLRBA_BNO,CPLRBA_BOF,CPODR_SEQ,CPODR_BNO,CPODR_BOF,CPODS,CPDRT,CPHBTFROM x$kcccp;

----------|----------|----------|----------|----------|----------|----------------|----------|----------

4294967295|4294967295| 65535| 39| 2| 0|4537434 | 0| 814881181

x$kcccp结果显示控制文件low cacherba为全f，没有脏块了。

建表，插入数据：

insert into hx.test select* from dba_objects;

1. 执行第一次日志切换：

SYS AS SYSDBA >altersystem switch logfile;

重做日志文件使用状况：

SYS AS SYSDBA > select GROUP#,THREAD#,SEQUENCE#,STATUS,FIRST_CHANGE#,NEXT_CHANGE# from v$log;

----------|----------|----------|----------------|-------------|------------

1| 1| 40|CURRENT | 4537578| 2.8147E+14

2| 1| 38|INACTIVE | 4537426| 4537434

3| 1| 39|ACTIVE | 4537434| 4537578

结果表明，3号日志有当前恢复需要的重做日志，而1号日志是当前使用的重做日志

查看报警日志，结果显示，分配了一个检查点任务，要求把RBA[0x28.2.10]之前的重做日志保护的脏数据写入数据文件，实际就是要求写完3号日志保护的buffercache

Beginning log switchcheckpoint up to RBA [0x28.2.10], SCN: 4537578

Thread 1 advanced to logsequence 40 (LGWR switch)

Current log# 1 seq# 40 mem# 0:/u01/oradata2/hx/redo01.log

看x$kcccp，当前low cache rba 仍是在3号重做日志：

SYS AS SYSDBA > SELECTCPLRBA_SEQ,CPLRBA_BNO,CPLRBA_BOF,CPODR_SEQ,CPODR_BNO,CPODR_BOF,CPODS,CPDRT,CPHBTFROM x$kcccp;

----------|----------|----------|----------|----------|----------|----------------|----------|----------

39| 3| 0| 40| 2| 0|4537578 | 16| 814881304

2. 第二次日志切换：

SYS AS SYSDBA >altersystem switch logfile;

SYS AS SYSDBA > select GROUP#,THREAD#,SEQUENCE#,STATUS,FIRST_CHANGE#,NEXT_CHANGE# from v$log;

----------|----------|----------|----------------|-------------|------------

1| 1| 40|ACTIVE | 4537578| 4537591

2| 1| 41|CURRENT | 4537591| 2.8147E+14

3| 1| 39|ACTIVE | 4537434| 4537578

重做日志文件结果显示，3号日志和1号日志虽然不是当前使用的，但是包含了恢复需要的重做日志。

看告警日志文件，又分配了一个任务，要求把RBA[0x29.2.10]之前的重做日志保护的buffercache写完。

Beginning log switchcheckpoint up to RBA [0x29.2.10], SCN: 4537591

Thread 1 advanced to logsequence 41 (LGWR switch)

Current log# 2 seq# 41 mem# 0:/u01/oradata2/hx/redo02.log

看x$kcccp视图,low cache rba一直没变

SYS AS SYSDBA > SELECTCPLRBA_SEQ,CPLRBA_BNO,CPLRBA_BOF,CPODR_SEQ,CPODR_BNO,CPODR_BOF,CPODS,CPDRT,CPHBTFROM x$kcccp;

----------|----------|----------|----------|----------|----------|----------------|----------|----------

39| 3| 0| 41| 2| 0|4537591 | 16| 814881318

3. 第三次切换

SYS AS SYSDBA >altersystem switch logfile;

看日志文件，结果显示，1号和2号日志均没有恢复需要的重做日志了，可以猜想，他们保护的buffercache全部写完了，他们对恢复不起作用了。

SYS AS SYSDBA >startlog;

----------|----------|----------|----------------|-------------|------------

1| 1| 40|INACTIVE | 4537578| 4537591

2| 1| 41|INACTIVE | 4537591| 4537609

3| 1| 42|CURRENT | 4537609| 2.8147E+14

SYS AS SYSDBA >SELECT CPLRBA_SEQ,CPLRBA_BNO,CPLRBA_BOF,CPODR_SEQ,CPODR_BNO,CPODR_BOF,CPODS,CPDRT,CPHBT FROM x$kccc;

看x$kcccp，的确没有脏块了。

----------|----------|----------|----------|----------|----------|----------------|----------|----------

4294967295|4294967295| 65535| 42| 3| 0|4537612 | 0| 814881333

那么，这其中都发生了什么呢？

告警日志文件：

Wed May 08 23:27:51 2013

Thread 1 cannot allocatenew log, sequence 42

Checkpoint not complete

Current log# 2 seq# 41 mem# 0:/u01/oradata2/hx/redo02.log

Wed May 08 23:27:55 2013

Completed checkpoint up toRBA [0x29.2.10], SCN: 4537591

Completed checkpoint up toRBA [0x28.2.10], SCN: 4537578

Beginning log switchcheckpoint up to RBA [0x2a.2.10], SCN: 4537609

Thread 1 advanced to logsequence 42 (LGWR switch)

Current log# 3 seq# 42 mem# 0:/u01/oradata2/hx/redo03.log

Completed checkpoint up toRBA [0x2a.2.10], SCN: 4537609

分析上面的日志，我的简单理解：oracle企图切换到3号日志，但是蓝色部分表明，3号日志包含了未完成的检查点，当前使用的还是2号文件。于是，oracle先把之前的脏块写完(包含1、2、3号重做日志保护的buffer cache全部写出)，再切换到3号日志。而且这里的确是花了较长时间的，检查点也变了。也就是说，这里实际是做了一次完全检查点?

郭老师，上面两行红色字体我不理解：为什么RBA[0x29.2.10]完成在RBA[0x28.2.10]之前？？

guoyJoe · 发表于 2013-5-9 07:13

本帖最后由 guoyJoe 于 2013-5-9 07:24 编辑

coloredice 发表于 2013-5-8 09:12
“实例崩溃后,再次启动数据库,oracle会到控制文件中读取low cache rba,这就是检查点位置.从此处开始应用重 ...

兄弟，你问题提的非常好，说明你之前思考过，呵呵。。。能否自己想办法去证明一下呢？
我可以明确的负责任的告诉你：on disk rba并不是是磁盘中重做日志文件的最后一条重做记录的rba
之前做个好多次实例恢复的测试，你可以用dump+监控alter_sid.log一起配合起来，多尝试几次，就明白了。

最近有点小忙，准备针对这个on disk rba搞个讨论话题。

guoyJoe · 发表于 2013-5-9 07:28

broadrange 发表于 2013-5-8 11:40
给出试验结果，我的结论也要修正一下，就是在下一组日志还是Active的状态下会先做完全检查点，再做一次增 ...

思路很好，值的我们更深入的思考。

broadrange · 发表于 2013-5-9 07:57

hexel 发表于 2013-5-9 01:27
郭老师，小弟带着问题来的，求指导！日志切换检查点是一种特殊的检查点：考虑到系统负载，日志切换时候，or ...

你的实验和我的实验是类似的，下一组切换的日志是active的话，运行手工切换日志的操作命令的时候明显是卡在那里等一会才返回的，应该是一次同步的完全检查点。
和你的实验不同的是，在第三次切换日志的时候日志中只有一个检查点完成记录，你的是两次。
你贴出来的命令中有手工检查点命令是怎么回事？按我的理解是手工检查点后，日志组的active状态肯定是要变成inactive的，因为实例恢复已经不需要该日志了。

broadrange · 发表于 2013-5-9 07:57

hexel 发表于 2013-5-9 01:27
郭老师，小弟带着问题来的，求指导！日志切换检查点是一种特殊的检查点：考虑到系统负载，日志切换时候，or ...

你的实验和我的实验是类似的，下一组切换的日志是active的话，运行手工切换日志的操作命令的时候明显是卡在那里等一会才返回的，应该是一次同步的完全检查点。
和你的实验不同的是，在第三次切换日志的时候日志中只有一个检查点完成记录，你的是两次。
你贴出来的命令中有手工检查点命令是怎么回事？按我的理解是手工检查点后，日志组的active状态肯定是要变成inactive的，因为实例恢复已经不需要该日志了。

[体系架构] [讨论话题]redolog switch会发生完全检查点还是增量检查点